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.

classification
Title: test_ssl and test_httplib.HTTPSTest crash randomly with "Windows fatal exception: access violation" on Windows
Type: Stage: resolved
Components: SSL, Tests Versions: Python 3.11
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: christian.heimes Nosy List: christian.heimes, db3l, erlendaasland, kj, miss-islington, pablogsal, vstinner
Priority: Keywords: patch

Created on 2021-05-27 17:13 by vstinner, last changed 2022-04-11 14:59 by admin. This issue is now closed.

Pull Requests
URL Status Linked Edit
PR 26439 merged pablogsal, 2021-05-28 22:44
PR 26441 merged miss-islington, 2021-05-28 23:30
Messages (28)
msg394573 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-05-27 17:13
Christian Heimes reported a crash in bpo-42972:
https://bugs.python.org/issue42972#msg394520
---
GH-26399 is failing with an access violation on Windows. It's failing in one of the flaky tests. I wonder if the segfault is related to flaky tests somehow...

https://dev.azure.com/Python/cpython/_build/results?buildId=81570&view=logs&j=c83831cd-3752-5cc7-2f01-8276919eb334

test_pha_optional (test.test_ssl.TestPostHandshakeAuth) ... ok
test_pha_optional_nocert (test.test_ssl.TestPostHandshakeAuth) ... ok
test_pha_required (test.test_ssl.TestPostHandshakeAuth) ... ok
Windows fatal exception: access violation

Current thread 0x000009e0 (most recent call first):
  File "D:\a\1\s\lib\linecache.py", line 63 in checkcache
  File "D:\a\1\s\lib\traceback.py", line 375 in extract
  File "D:\a\1\s\lib\traceback.py", line 494 in __init__
  File "D:\a\1\s\lib\traceback.py", line 132 in format_exception
  File "D:\a\1\s\lib\test\test_ssl.py", line 262 in handle_error
  File "D:\a\1\s\lib\test\test_ssl.py", line 2530 in run
  File "D:\a\1\s\lib\threading.py", line 1006 in _bootstrap_inner
  File "D:\a\1\s\lib\threading.py", line 963 in _bootstrap

Thread 0x000003c4 (most recent call first):
  File "D:\a\1\s\lib\threading.py", line 1102 in _wait_for_tstate_lock
  File "D:\a\1\s\lib\threading.py", line 1086 in join
  File "D:\a\1\s\lib\test\test_ssl.py", line 2604 in run
  File "D:\a\1\s\lib\threading.py", line 1006 in _bootstrap_inner
  File "D:\a\1\s\lib\threading.py", line 963 in _bootstrap

Thread 0x00001700 (most recent call first):
  File "D:\a\1\s\lib\ssl.py", line 1131 in read
  File "D:\a\1\s\lib\ssl.py", line 1256 in recv
  File "D:\a\1\s\lib\test\test_ssl.py", line 4471 in test_pha_required_nocert
  File "D:\a\1\s\lib\unittest\case.py", line 549 in _callTestMethod
  File "D:\a\1\s\lib\unittest\case.py", line 592 in run
  File "D:\a\1\s\lib\unittest\case.py", line 652 in __call__
  File "D:\a\1\s\lib\unittest\suite.py", line 122 in run
  File "D:\a\1\s\lib\unittest\suite.py", line 84 in __call__
  File "D:\a\1\s\lib\unittest\suite.py", line 122 in run
  File "D:\a\1\s\lib\unittest\suite.py", line 84 in __call__
  File "D:\a\1\s\lib\unittest\runner.py", line 176 in run
  File "D:\a\1\s\lib\test\support\__init__.py", line 959 in _run_suite
  File "D:\a\1\s\lib\test\support\__init__.py", line 1082 in run_unittest
  File "D:\a\1\s\lib\test\test_ssl.py", line 5007 in test_main
  File "D:\a\1\s\lib\test\libregrtest\runtest.py", line 246 in _runtest_inner2
  File "D:\a\1\s\lib\test\libregrtest\runtest.py", line 282 in _runtest_inner
  File "D:\a\1\s\lib\test\libregrtest\runtest.py", line 154 in _runtest
  File "D:\a\1\s\lib\test\__main__.py", line 2 in <module>
  File "D:\a\1\s\lib\runpy.py", line 86 in _run_code
  File "D:\a\1\s\lib\runpy.py", line 196 in _run_module_as_main
##[error]Cmd.exe exited with code '-1073741819'.
---


Erlend E. Aasland added:
---
Hm, I'm unable to reproduce it w/addr sanitiser on macOS (FWIW).

$ ./python.exe -m test test_ssl -F -u all -m test_pha_required_nocert

Passing 1000 successful runs now. I'll see if I can get a Win dev env set up later.
---

I may be related to commit dcb8786a9848516e823e090bb36079678913d8d3 "bpo-42972: Fully implement GC protocol for ssl heap types (GH-26370)".
msg394581 - (view) Author: Erlend E. Aasland (erlendaasland) * (Python triager) Date: 2021-05-27 17:48
GH 26411, run id 2687367477 also failed with an access violation:
https://github.com/python/cpython/pull/26411/checks?check_run_id=2687367477

Not in test_pha_required_nocert, but test_local_bad_hostname.

May be related.
msg394599 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-05-27 20:55
Crash also seen on test_httplib:

(...)
test_attributes (test.test_httplib.HTTPSTest) ... ok
test_host_port (test.test_httplib.HTTPSTest) ... ok
Windows fatal exception: access violation

Current thread 0x000011ec (most recent call first):
  File "D:\a\cpython\cpython\lib\socket.py", line 502 in close
  File "D:\a\cpython\cpython\lib\ssl.py", line 1072 in _create
  File "D:\a\cpython\cpython\lib\ssl.py", line 518 in wrap_socket
  File "D:\a\cpython\cpython\lib\test\ssl_servers.py", line 37 in get_request
  File "D:\a\cpython\cpython\lib\socketserver.py", line 311 in _handle_request_noblock
  File "D:\a\cpython\cpython\lib\socketserver.py", line 237 in serve_forever
  File "D:\a\cpython\cpython\lib\test\ssl_servers.py", line 142 in run
  File "D:\a\cpython\cpython\lib\threading.py", line 1006 in _bootstrap_inner
  File "D:\a\cpython\cpython\lib\threading.py", line 963 in _bootstrap

Thread 0x000013ec (most recent call first):
  File "D:\a\cpython\cpython\lib\socket.py", line 496 in _real_close
  File "D:\a\cpython\cpython\lib\ssl.py", line 1330 in _real_close
  File "D:\a\cpython\cpython\lib\socket.py", line 502 in close
  File "D:\a\cpython\cpython\lib\ssl.py", line 1072 in _create
  File "D:\a\cpython\cpython\lib\ssl.py", line 518 in wrap_socket
  File "D:\a\cpython\cpython\lib\http\client.py", line 1448 in connect
  File "D:\a\cpython\cpython\lib\http\client.py", line 969 in send
  File "D:\a\cpython\cpython\lib\http\client.py", line 1031 in _send_output
  File "D:\a\cpython\cpython\lib\http\client.py", line 1271 in endheaders
  File "D:\a\cpython\cpython\lib\http\client.py", line 1322 in _send_request
  File "D:\a\cpython\cpython\lib\http\client.py", line 1276 in request
  File "D:\a\cpython\cpython\lib\test\test_httplib.py", line 1950 in test_local_bad_hostname
  File "D:\a\cpython\cpython\lib\unittest\case.py", line 549 in _callTestMethod
  File "D:\a\cpython\cpython\lib\unittest\case.py", line 592 in run
  File "D:\a\cpython\cpython\lib\unittest\case.py", line 652 in __call__
  File "D:\a\cpython\cpython\lib\unittest\suite.py", line 122 in run
  File "D:\a\cpython\cpython\lib\unittest\suite.py", line 84 in __call__
  File "D:\a\cpython\cpython\lib\unittest\suite.py", line 122 in run
  File "D:\a\cpython\cpython\lib\unittest\suite.py", line 84 in __call__
  File "D:\a\cpython\cpython\lib\unittest\suite.py", line 122 in run
  File "D:\a\cpython\cpython\lib\unittest\suite.py", line 84 in __call__
  File "D:\a\cpython\cpython\lib\unittest\runner.py", line 176 in run
  File "D:\a\cpython\cpython\lib\test\support\__init__.py", line 959 in _run_suite
  File "D:\a\cpython\cpython\lib\test\support\__init__.py", line 1082 in run_unittest
  File "D:\a\cpython\cpython\lib\test\libregrtest\runtest.py", line 210 in _test_module
  File "D:\a\cpython\cpython\lib\test\libregrtest\runtest.py", line 246 in _runtest_inner2
  File "D:\a\cpython\cpython\lib\test\libregrtest\runtest.py", line 282 in _runtest_inner
  File "D:\a\cpython\cpython\lib\test\libregrtest\runtest.py", line 154 in _runtest
  File "D:\a\cpython\cpython\lib\test\libregrtest\runtest.py", line 194 in runtest
  File "D:\a\cpython\cpython\lib\test\libregrtest\main.py", line 321 in rerun_failed_tests
  File "D:\a\cpython\cpython\lib\test\libregrtest\main.py", line 698 in _main
  File "D:\a\cpython\cpython\lib\test\libregrtest\main.py", line 641 in main
  File "D:\a\cpython\cpython\lib\test\libregrtest\main.py", line 719 in main
  File "D:\a\cpython\cpython\lib\test\__main__.py", line 2 in <module>
  File "D:\a\cpython\cpython\lib\runpy.py", line 86 in _run_code
  File "D:\a\cpython\cpython\lib\runpy.py", line 196 in _run_module_as_main
test_local_bad_hostname (test.test_httplib.HTTPSTest) ... 
Error: Process completed with exit code 1.

test.pythoninfo:

ssl.HAS_SNI: True
ssl.OPENSSL_VERSION: OpenSSL 1.1.1k  25 Mar 2021
ssl.OPENSSL_VERSION_INFO: (1, 1, 1, 11, 15)
ssl.OP_ALL: -0x7fffffac
ssl.OP_NO_TLSv1_1: 0x10000000
ssl.SSLContext.maximum_version: MAXIMUM_SUPPORTED
ssl.SSLContext.minimum_version: TLSv1_2
ssl.SSLContext.options: OP_NO_COMPRESSION|OP_ENABLE_MIDDLEBOX_COMPAT|OP_CIPHER_SERVER_PREFERENCE|OP_NO_SSLv3|0x54
ssl.SSLContext.protocol: PROTOCOL_TLS_CLIENT
ssl.SSLContext.verify_mode: CERT_REQUIRED
ssl.default_https_context.maximum_version: MAXIMUM_SUPPORTED
ssl.default_https_context.minimum_version: TLSv1_2
ssl.default_https_context.options: OP_NO_COMPRESSION|OP_ENABLE_MIDDLEBOX_COMPAT|OP_CIPHER_SERVER_PREFERENCE|OP_NO_SSLv3|0x54
ssl.default_https_context.protocol: PROTOCOL_TLS_CLIENT
ssl.default_https_context.verify_mode: CERT_REQUIRED
ssl.stdlib_context.maximum_version: MAXIMUM_SUPPORTED
ssl.stdlib_context.minimum_version: TLSv1_2
ssl.stdlib_context.options: OP_NO_COMPRESSION|OP_ENABLE_MIDDLEBOX_COMPAT|OP_CIPHER_SERVER_PREFERENCE|OP_NO_SSLv3|0x54
ssl.stdlib_context.protocol: PROTOCOL_TLS_CLIENT
ssl.stdlib_context.verify_mode: CERT_NONE
msg394600 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-05-27 20:56
I forgot the link:
https://github.com/python/cpython/pull/26411/checks?check_run_id=2687367477

Oh right, Erlend already reported exactly the same crash :-)
msg394605 - (view) Author: Pablo Galindo Salgado (pablogsal) * (Python committer) Date: 2021-05-27 21:14
Is this happening on the current 3.10 or just with a specific PR?
msg394606 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-05-27 21:17
> Is this happening on the current 3.10 or just with a specific PR?

The test_httplib crash occured on https://github.com/python/cpython/pull/26411 PR which is unrelated to ssl.
msg394608 - (view) Author: Pablo Galindo Salgado (pablogsal) * (Python committer) Date: 2021-05-27 21:24
Ugh, should we make this a release blocker?
msg394614 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-05-27 22:58
This issue now prevents me to merge https://github.com/python/cpython/pull/26414 backport :-(

I'm debugging it on Windows.

I tried:

vstinner@DESKTOP-DK7VBIL C:\vstinner\python\main>python -u -X dev -m test -u all test_ssl -m test_pha_required_nocert -v -F -j2
(...)
0:00:35 load avg: 8.32 [ 77/1] test_ssl failed
test_ssl: testing with 'OpenSSL 1.1.1k  25 Mar 2021' (1, 1, 1, 11, 15)
          under Windows ('10', '10.0.19042', 'SP0', 'Multiprocessor Free')
          HAS_SNI = True
          OP_ALL = 0x-7fffffac
          OP_NO_TLSv1_1 = 0x10000000
test_pha_required_nocert (test.test_ssl.TestPostHandshakeAuth) ...  server:  new connection from ('127.0.0.1', 51115)
 client cert is None
 client did not provide a cert
 server: connection cipher is now ('TLS_AES_256_GCM_SHA384', 'TLSv1.3', 256)
TLS: (<ssl.SSLSocket fd=680, family=AF_INET, type=SOCK_STREAM, proto=0, laddr=('127.0.0.1', 51114), raddr=('127.0.0.1', 51115)>, 'write', TLSVersion.TLS
v1_3, _TLSContentType.ALERT, _TLSAlertType.CERTIFICATE_REQUIRED, b'\x02t')
Test server failure:
Traceback (most recent call last):
   File "C:\vstinner\python\main\lib\test\test_ssl.py", line 2444, in run
    msg = self.read()
   File "C:\vstinner\python\main\lib\test\test_ssl.py", line 2421, in read
    return self.sslconn.read()
   File "C:\vstinner\python\main\lib\ssl.py", line 1131, in read
    return self._sslobj.read(len)
 ssl.SSLError: [SSL: PEER_DID_NOT_RETURN_A_CERTIFICATE] peer did not return a certificate (_ssl.c:2523)
FAIL

======================================================================
FAIL: test_pha_required_nocert (test.test_ssl.TestPostHandshakeAuth)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "C:\vstinner\python\main\lib\test\test_ssl.py", line 4458, in test_pha_required_nocert
    with self.assertRaisesRegex(
AssertionError: SSLError not raised


This is not the crash, but the fact that the test is not reliable doesn't help to debug :-(


Moreover, I had to patch unittest locally, since a frame globals was None!?

test test_ssl crashed -- Traceback (most recent call last):
  File "C:\vstinner\python\main\lib\test\libregrtest\runtest.py", line 282, in _runtest_inner
    refleak = _runtest_inner2(ns, test_name)
  (...)
  File "C:\vstinner\python\main\lib\unittest\result.py", line 209, in _count_relevant_tb_levels
    while tb and not self._is_relevant_tb_level(tb):
  File "C:\vstinner\python\main\lib\unittest\result.py", line 205, in _is_relevant_tb_level
    return '__unittest' in tb.tb_frame.f_globals
TypeError: argument of type 'NoneType' is not iterable
msg394615 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-05-27 23:05
Another error (not the crash):

test_pha_required_nocert (test.test_ssl.TestPostHandshakeAuth) ...  server:  new connection from ('127.0.0.1', 51128)
 client cert is None
 client did not provide a cert
 server: connection cipher is now ('TLS_AES_256_GCM_SHA384', 'TLSv1.3', 256)
TLS: (<ssl.SSLSocket fd=688, family=AF_INET, type=SOCK_STREAM, proto=0, laddr=('127.0.0.1', 51127), raddr=('127.0.0.1', 51128)>, 'write', TLSVersion.TLS
v1_3, _TLSContentType.ALERT, _TLSAlertType.CERTIFICATE_REQUIRED, b'\x02t')
Test server failure:
Traceback (most recent call last):
   File "C:\vstinner\python\main\lib\test\test_ssl.py", line 2444, in run
    msg = self.read()
   File "C:\vstinner\python\main\lib\test\test_ssl.py", line 2421, in read
    return self.sslconn.read()
   File "C:\vstinner\python\main\lib\ssl.py", line 1131, in read
    return self._sslobj.read(len)
 ssl.SSLError: [SSL: PEER_DID_NOT_RETURN_A_CERTIFICATE] peer did not return a certificate (_ssl.c:2523)
FAIL

======================================================================
FAIL: test_pha_required_nocert (test.test_ssl.TestPostHandshakeAuth)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "C:\vstinner\python\main\lib\test\test_ssl.py", line 4463, in test_pha_required_nocert
    self.assertEqual(s.recv(1024), b'OK\n')
AssertionError: b'' != b'OK\n'
msg394617 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-05-27 23:38
https://dev.azure.com/Python/cpython/_build/results?buildId=81570&view=logs&j=c83831cd-3752-5cc7-2f01-8276919eb334

test.pythoninfo

Py_DEBUG: No (sys.gettotalrefcount() missing)

platform.architecture: 64bit WindowsPE
platform.platform: Windows-10-10.0.17763-SP0

ssl.HAS_SNI: True
ssl.OPENSSL_VERSION: OpenSSL 1.1.1k  25 Mar 2021
ssl.OPENSSL_VERSION_INFO: (1, 1, 1, 11, 15)
ssl.OP_ALL: -0x7fffffac
ssl.OP_NO_TLSv1_1: 0x10000000
ssl.SSLContext.maximum_version: MAXIMUM_SUPPORTED
ssl.SSLContext.minimum_version: TLSv1_2
ssl.SSLContext.options: OP_NO_COMPRESSION|OP_ENABLE_MIDDLEBOX_COMPAT|OP_CIPHER_SERVER_PREFERENCE|OP_NO_SSLv3|0x54
ssl.SSLContext.protocol: PROTOCOL_TLS_CLIENT
ssl.SSLContext.verify_mode: CERT_REQUIRED

sys.version: 3.10.0b1+ (remotes/origin/de21daee57079ec694adc248a39e718ea0cf43f9:de21daee5, May 27 2021, ) [MSC v.1928 64 bit (AMD64)]
sys.version_info: sys.version_info(major=3, minor=10, micro=0, releaselevel='beta', serial=1)
sys.windowsversion: sys.getwindowsversion(major=10, minor=0, build=17763, platform=2, service_pack='')
msg394619 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-05-27 23:40
https://github.com/python/cpython/pull/26411/checks?check_run_id=2687367477

test.pythoninfo:

Py_DEBUG: No (sys.gettotalrefcount() missing)
os.cpu_count: 2
os.environ[VS140COMNTOOLS]: C:\Program Files (x86)\Microsoft Visual Studio 14.0\Common7\Tools\

platform.architecture: 64bit WindowsPE
platform.platform: Windows-10-10.0.17763-SP0


ssl.HAS_SNI: True
ssl.OPENSSL_VERSION: OpenSSL 1.1.1k  25 Mar 2021
ssl.OPENSSL_VERSION_INFO: (1, 1, 1, 11, 15)
ssl.OP_ALL: -0x7fffffac
ssl.OP_NO_TLSv1_1: 0x10000000
ssl.SSLContext.maximum_version: MAXIMUM_SUPPORTED
ssl.SSLContext.minimum_version: TLSv1_2
ssl.SSLContext.options: OP_NO_COMPRESSION|OP_ENABLE_MIDDLEBOX_COMPAT|OP_CIPHER_SERVER_PREFERENCE|OP_NO_SSLv3|0x54
ssl.SSLContext.protocol: PROTOCOL_TLS_CLIENT
ssl.SSLContext.verify_mode: CERT_REQUIRED


sys.version: 3.10.0b1+ (remotes/pull/26411/merge:dddae6a, May 27 2021, 17:25:25) [MSC v.1928 64 bit (AMD64)]
sys.version_info: sys.version_info(major=3, minor=10, micro=0, releaselevel='beta', serial=1)
sys.windowsversion: sys.getwindowsversion(major=10, minor=0, build=17763, platform=2, service_pack='')
msg394621 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-05-28 00:23
So far, I failed to reproduce the crash on my up-to-date local Windows 10 VM ("Version 21H1 (OS Build 19043.985)"). I built Python in release mode ("PCbuild\build.bat -e -p x64" command). I'm using Visual Studio 2019.

test.pythoninfo:

Py_DEBUG: No (sys.gettotalrefcount() missing)
os.cpu_count: 2
platform.architecture: 64bit WindowsPE
platform.platform: Windows-10-10.0.19043-SP0

ssl.HAS_SNI: True
ssl.OPENSSL_VERSION: OpenSSL 1.1.1k  25 Mar 2021
ssl.OPENSSL_VERSION_INFO: (1, 1, 1, 11, 15)
ssl.OP_ALL: -0x7fffffac
ssl.OP_NO_TLSv1_1: 0x10000000
ssl.SSLContext.maximum_version: MAXIMUM_SUPPORTED
ssl.SSLContext.minimum_version: TLSv1_2
ssl.SSLContext.options: OP_NO_COMPRESSION|OP_ENABLE_MIDDLEBOX_COMPAT|OP_CIPHER_SERVER_PREFERENCE|OP_NO_SSLv3|0x54
ssl.SSLContext.protocol: PROTOCOL_TLS_CLIENT
ssl.SSLContext.verify_mode: CERT_REQUIRED

sys.version: 3.10.0b1+ (heads/pr/26411:e269fa13a7, May 28 2021, 00:46:49) [MSC v.1928 64 bit (AMD64)]
sys.version_info: sys.version_info(major=3, minor=10, micro=0, releaselevel='beta', serial=1)
sys.windowsversion: sys.getwindowsversion(major=10, minor=0, build=19043, platform=2, service_pack='')
msg394624 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-05-28 00:48
Other recent ssl issues:

* bpo-43921
* bpo-44229
* bpo-44237
msg394654 - (view) Author: Ken Jin (kj) * (Python committer) Date: 2021-05-28 12:10
Sorry, I introduced the test_httplib regression on Windows with GH-26381 commit 0fa282c55f1a45765340cb24ed65c90ffe2aa405. I made a second PR GH-26429 to fix it.
msg394655 - (view) Author: Ken Jin (kj) * (Python committer) Date: 2021-05-28 12:17
Oops, nevermind I mixed the issues up, please ignore the previous message. The regression I introduced in main was a related assertionerror in test_httplib but doesn't affect 3.10. 3.10 still fails randomly for unknown reasons.
msg394661 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-05-28 14:21
Ken Jin:
"Sorry, I introduced the test_httplib regression on Windows with GH-26381 commit 0fa282c55f1a45765340cb24ed65c90ffe2aa405. I made a second PR GH-26429 to fix it."

That would help to fix the issue, sadly the crash is earlier to your PR merge, and test_httplib doesn't use asyncio.
msg394685 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-05-28 20:19
Oh, test_ssl also crashed on Linux on the 3.10 branch, commit 0d399516320d8dfce4453037338659cef3a2adf4.

AMD64 Fedora Stable 3.10
https://buildbot.python.org/all/#/builders/659/builds/70

test.pythoninfo:

ssl.HAS_SNI: True
ssl.OPENSSL_VERSION: OpenSSL 1.1.1k  FIPS 25 Mar 2021
ssl.OPENSSL_VERSION_INFO: (1, 1, 1, 11, 15)
ssl.OP_ALL: 0x80000054
ssl.OP_NO_TLSv1_1: 0x10000000
ssl.SSLContext.maximum_version: TLSv1_3
ssl.SSLContext.minimum_version: TLSv1_2
ssl.SSLContext.options: OP_NO_COMPRESSION|OP_ENABLE_MIDDLEBOX_COMPAT|OP_CIPHER_SERVER_PREFERENCE|OP_NO_SSLv3|0x80000054
ssl.SSLContext.protocol: PROTOCOL_TLS_CLIENT
ssl.SSLContext.verify_mode: CERT_REQUIRED

Log:

(...)
test_sni_callback_wrong_return_type (test.test_ssl.ThreadedTests) ... ok
test_socketserver (test.test_ssl.ThreadedTests)
Using socketserver to create and manage SSL connections. ... ok
Fatal Python error: Segmentation fault

Current thread 0x00007f9de2d1f640 (most recent call first):
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/linecache.py", line 72 in checkcache
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/traceback.py", line 375 in extract
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/traceback.py", line 494 in __init__
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/traceback.py", line 132 in format_exception
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/test/test_ssl.py", line 262 in handle_error
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/test/test_ssl.py", line 2401 in wrap_conn
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/test/test_ssl.py", line 2444 in run
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/threading.py", line 1006 in _bootstrap_inner
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/threading.py", line 963 in _bootstrap

Thread 0x00007f9de0d1b640 (most recent call first):
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/threading.py", line 1102 in _wait_for_tstate_lock
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/threading.py", line 1086 in join
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/test/test_ssl.py", line 2604 in run
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/threading.py", line 1006 in _bootstrap_inner
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/threading.py", line 963 in _bootstrap

Thread 0x00007f9df0b5c740 (most recent call first):
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/threading.py", line 1102 in _wait_for_tstate_lock
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/threading.py", line 1086 in join
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/test/test_ssl.py", line 2583 in __exit__
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/test/test_ssl.py", line 3273 in test_ssl_cert_verify_error
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/unittest/case.py", line 549 in _callTestMethod
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/unittest/case.py", line 592 in run
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/unittest/case.py", line 652 in __call__
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/unittest/suite.py", line 122 in run
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/unittest/suite.py", line 84 in __call__
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/unittest/suite.py", line 122 in run
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/unittest/suite.py", line 84 in __call__
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/unittest/runner.py", line 176 in run
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/test/support/__init__.py", line 959 in _run_suite
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/test/support/__init__.py", line 1082 in run_unittest
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/test/test_ssl.py", line 5007 in test_main
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/test/libregrtest/runtest.py", line 246 in _runtest_inner2
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/test/libregrtest/runtest.py", line 282 in _runtest_inner
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/test/libregrtest/runtest.py", line 154 in _runtest
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/test/libregrtest/runtest.py", line 194 in runtest
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/test/libregrtest/main.py", line 321 in rerun_failed_tests
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/test/libregrtest/main.py", line 698 in _main
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/test/libregrtest/main.py", line 641 in main
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/test/libregrtest/main.py", line 719 in main
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/test/__main__.py", line 2 in <module>
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/runpy.py", line 86 in _run_code
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/runpy.py", line 196 in _run_module_as_main

Extension modules: _testcapi (total: 1)
make: *** [Makefile:1256: buildbottest] Segmentation fault (core dumped)
msg394687 - (view) Author: David Bolen (db3l) * Date: 2021-05-28 20:29
The win10 buildbot appears to have this failure consistently (100%) on the 3.10 branch.  The first such failure appears to be yesterday (https://buildbot.python.org/all/#/builders/600/builds/79), following commit da8097aaf5a55c23f5b5ddbeffc2d90d06e00d93 - GC changes for mmap.

I'm not yet having much luck reproducing manually (which is perplexing given the consistent failures during the automatic tests).  I did see one test run where 8 other tests failed instead, but haven't been able to repeat.  The 3.x branch also seems to be doing fine on the buildbot while including the same patch that was cherry picked for 3.10.

So this could be a false lead, but it might be another place to review.  Or for anyone who can at least sporadically get a failure (I'm still trying), something to try reverting.
msg394688 - (view) Author: Pablo Galindo Salgado (pablogsal) * (Python committer) Date: 2021-05-28 20:42
I'm marking this as a release blocker for the next beta.
msg394691 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-05-28 21:49
Maybe the problem is related to Python frames. I think Mark Shannon made changes related to frames recently in 3.10 and main branches.

It's strange that I got such error:

  File "C:\vstinner\python\main\lib\unittest\result.py", line 205, in _is_relevant_tb_level
    return '__unittest' in tb.tb_frame.f_globals
TypeError: argument of type 'NoneType' is not iterable

It's also strange that two crashes occurred while reading a traceback:

Windows fatal exception: access violation

Current thread 0x000009e0 (most recent call first):
  File "D:\a\1\s\lib\linecache.py", line 63 in checkcache
  File "D:\a\1\s\lib\traceback.py", line 375 in extract
  File "D:\a\1\s\lib\traceback.py", line 494 in __init__
  File "D:\a\1\s\lib\traceback.py", line 132 in format_exception
  File "D:\a\1\s\lib\test\test_ssl.py", line 262 in handle_error

and:

Fatal Python error: Segmentation fault

Current thread 0x00007f9de2d1f640 (most recent call first):
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/linecache.py", line 72 in checkcache
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/traceback.py", line 375 in extract
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/traceback.py", line 494 in __init__
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/traceback.py", line 132 in format_exception
  File "/home/buildbot/buildarea/3.10.cstratak-fedora-stable-x86_64/build/Lib/test/test_ssl.py", line 262 in handle_error

Extract of test_ssl.py:

def handle_error(prefix):
    exc_format = ' '.join(traceback.format_exception(*sys.exc_info()))
    ...

Maybe sometimes somehow, frames are invalid.

Maybe test_ssl/test_httplib only makes the crash more likely, but there is a regression to frames somewhere.
msg394693 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-05-28 22:00
Oh, I forgot to mention that I saw the "TypeError: argument of type 'NoneType' is not iterable" error on the main branch, not on the 3.10 branch.
msg394694 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-05-28 22:09
I remove Mark from the issue. I may open later a different issue for tb_frame.f_globals=None, but it's unrelated to this bug.

I can reproduce the issue with a small hack to make GC collections make likely:

diff --git a/Lib/site.py b/Lib/site.py
index 939893eb5e..4103792e84 100644
--- a/Lib/site.py
+++ b/Lib/site.py
@@ -672,3 +672,6 @@ def exists(path):
 
 if __name__ == '__main__':
     _script()
+
+import gc
+gc.set_threshold(5)


With this patch, it becomes trivial to reproduce the crash on Linux:

$ ./python -m test test_ssl -m test_ssl_cert_verify_error -v 
(...)
Fatal Python error: Segmentation fault

Current thread 0x00007fd0f72a8640 (most recent call first):
  File "/home/vstinner/python/3.10/Lib/traceback.py", line 132 in format_exception
  File "/home/vstinner/python/3.10/Lib/test/test_ssl.py", line 262 in handle_error
  File "/home/vstinner/python/3.10/Lib/test/test_ssl.py", line 2401 in wrap_conn
(...)

So the problem is that _ssl.SSLError type traverse function is NULL.
msg394695 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-05-28 22:16
For me, there are different issues:

* PyType_FromSpec() must fail if a type is declared with Py_TPFLAGS_HAVE_GC but its tp_traverse function is NULL.
* _ssl.SSLError must implement the tp_traverse slot

Moreover, in debug mode, PyObject_GC_Track() calls the traverse function to ensure that it's safe to call it. PyObject_GC_Track() must crash of tp_traverse is NULL. If it didn't track, it means that the _ssl.SSLError instance was not tracked by the GC. Is that ok? Objects implementing the GC protocol should be tracked by the GC, no?

An exception is *likely* to be part of a reference cycle because it contains a traceback which contains frames which contains variables, and one variable can be the exception.
msg394696 - (view) Author: Pablo Galindo Salgado (pablogsal) * (Python committer) Date: 2021-05-28 22:19
The regression was introduced by

https://github.com/python/cpython/commit/dcb8786a9848516e823e090bb36079678913d8d3
msg394698 - (view) Author: David Bolen (db3l) * Date: 2021-05-28 22:23
Oddly, it turns out it's the "--junit-xml" parameter during buildbot tests that is making it reproducible there.

  Pass: python_d -m test.regrtest test_ssl
  Fail: python_d -m test.regrtest --junit-xml out.xml test_ssl

The latter consistently fails all of the time for me manually.

I also found what I think is the same commit Pablo just referenced (albeit the cherry pick version on the 3.10 branch) - ea47a8a71ad56ec349f02bf8c6a1d3bf04acabcc.  Reverting just that commit as part of the latest 3.10 source passes.
msg394699 - (view) Author: Pablo Galindo Salgado (pablogsal) * (Python committer) Date: 2021-05-28 22:27
Easier reproducer:

>>> import gc
>>> gc.get_referrers(x)
AddressSanitizer:DEADLYSIGNAL
=================================================================
==17017==ERROR: AddressSanitizer: SEGV on unknown address 0x000000000000 (pc 0x000000000000 bp 0x7fff93f8f7a0 sp 0x7fff93f8f758 T0)
==17017==Hint: pc points to the zero page.
==17017==The signal is caused by a READ memory access.
==17017==Hint: address points to the zero page.
    #0 0x0  (<unknown module>)

AddressSanitizer can not provide additional info.
SUMMARY: AddressSanitizer: SEGV (<unknown module>)
==17017==ABORTING
msg394703 - (view) Author: Pablo Galindo Salgado (pablogsal) * (Python committer) Date: 2021-05-28 23:29
New changeset 8b4312b909abff3100c1f18fb3efa5c25617fee3 by Pablo Galindo in branch 'main':
bpo-44252: Correctly implement gc support for SSLError objects (GH-26439)
https://github.com/python/cpython/commit/8b4312b909abff3100c1f18fb3efa5c25617fee3
msg394704 - (view) Author: Pablo Galindo Salgado (pablogsal) * (Python committer) Date: 2021-05-28 23:47
New changeset a7aa105702998fea7f6671b7358144146e4bc47f by Miss Islington (bot) in branch '3.10':
bpo-44252: Correctly implement gc support for SSLError objects (GH-26439) (GH-26441)
https://github.com/python/cpython/commit/a7aa105702998fea7f6671b7358144146e4bc47f
History
Date User Action Args
2022-04-11 14:59:46adminsetgithub: 88418
2021-05-29 00:11:19pablogsalsetpriority: release blocker ->
status: open -> closed
resolution: fixed
stage: patch review -> resolved
2021-05-28 23:47:50pablogsalsetmessages: + msg394704
2021-05-28 23:30:10miss-islingtonsetnosy: + miss-islington
pull_requests: + pull_request25033
2021-05-28 23:29:56pablogsalsetmessages: + msg394703
2021-05-28 22:44:46pablogsalsetkeywords: + patch
stage: patch review
pull_requests: + pull_request25031
2021-05-28 22:27:46pablogsalsetmessages: + msg394699
2021-05-28 22:23:33db3lsetmessages: + msg394698
2021-05-28 22:19:05pablogsalsetmessages: + msg394696
2021-05-28 22:16:31vstinnersetmessages: + msg394695
2021-05-28 22:09:55vstinnersetnosy: - Mark.Shannon
messages: + msg394694
2021-05-28 22:00:20vstinnersetmessages: + msg394693
2021-05-28 21:49:39vstinnersetnosy: + Mark.Shannon
messages: + msg394691
2021-05-28 20:42:43pablogsalsetpriority: release blocker

messages: + msg394688
2021-05-28 20:29:13db3lsetnosy: + db3l
messages: + msg394687
2021-05-28 20:19:17vstinnersetmessages: + msg394685
2021-05-28 14:21:04vstinnersetmessages: + msg394661
2021-05-28 12:17:37kjsetmessages: + msg394655
2021-05-28 12:10:27kjsetnosy: + kj
messages: + msg394654
2021-05-28 00:48:39vstinnersetmessages: + msg394624
2021-05-28 00:23:21vstinnersetmessages: + msg394621
2021-05-27 23:40:08vstinnersetmessages: + msg394619
2021-05-27 23:38:09vstinnersetmessages: + msg394617
2021-05-27 23:05:41vstinnersetmessages: + msg394615
2021-05-27 22:58:03vstinnersetmessages: + msg394614
2021-05-27 21:24:57pablogsalsetmessages: + msg394608
2021-05-27 21:17:22vstinnersetmessages: + msg394606
2021-05-27 21:14:40pablogsalsetnosy: + pablogsal
messages: + msg394605
2021-05-27 20:57:23vstinnersettitle: test_ssl: test_pha_required_nocert() crashs randomly with "Windows fatal exception: access violation" on Windows -> test_ssl and test_httplib.HTTPSTest crash randomly with "Windows fatal exception: access violation" on Windows
2021-05-27 20:56:25vstinnersetmessages: + msg394600
2021-05-27 20:55:10vstinnersetmessages: + msg394599
2021-05-27 17:48:10erlendaaslandsetmessages: + msg394581
2021-05-27 17:15:14vstinnersetpriority: normal -> (no value)
nosy: + erlendaasland
2021-05-27 17:13:50vstinnercreate