gh-108342: Make ssl TestPreHandshakeClose more reliable#108370

vstinner

In preauth tests of test_ssl, explicitly break reference cycles
invoving SingleConnectionTestServerThread to make sure that the
thread is deleted. Otherwise, the test marks the environment as
altered because the threading module sees a "dangling thread"
(SingleConnectionTestServerThread). This test leak was introduced
by the test added for the fix of issue CVE-2023-40217: Bypass TLS handshake on closed sockets #108310.
Use support.SHORT_TIMEOUT instead of hardcoded 1.0 or 2.0 seconds
timeout.
SingleConnectionTestServerThread.run() catchs TimeoutError
Fix a race condition (missing synchronization) in
test_preauth_data_to_tls_client(): the server now waits until the
client connect() completed in call_after_accept().
Replace socket.send() with socket.sendall()
test_https_client_non_tls_response_ignored() calls server.join()
explicitly.
Replace "localhost" with server.listener.getsockname()[0].

Issue: test_ssl fails with "env changed" on ARM64 Windows buildbot: thread doesn't catch TimeoutError #108342

vstinner

Non-Linux platforms have this issue because of the non_linux_skip_if_other_okay_error() code path in these tests. skipTest() in called on non-Linux platforms in some cases:

            # On Windows the TCP RST leads to a ConnectionResetError
            # (ECONNRESET) which Linux doesn't appear to surface to userspace.
            # If wrap_socket() winds up on the "if connected:" path and doing
            # the actual wrapping... we get an SSLError from OpenSSL. Typically
            # WRONG_VERSION_NUMBER. While appropriate, neither is the scenario
            # we're specifically trying to test. The way this test is written
            # is known to work on Linux. We'll skip it anywhere else that it
            # does not present as doing so.

Without this change, test_ssl fails with "env changed" on Windows (on an idle machine):

C:\victor\python\main>python -m test test_ssl -u all --fail-env-changed -v -m "*preauth*" 
(...)
test_preauth_data_to_tls_client (test.test_ssl.TestPreHandshakeClose.test_preauth_data_to_tls_client) ... skipped "Could not recreate conditions on win32: err=ConnectionResetError(10054, 'An existing connection was forcibly closed by the remote host', None, 10054, None)"
test_preauth_data_to_tls_server (test.test_ssl.TestPreHandshakeClose.test_preauth_data_to_tls_server) ... skipped "Could not recreate conditions on win32: err=ConnectionResetError(10054, 'An existing connection was forcibly closed by the remote host', None, 10054, None)"
Warning -- threading_cleanup() failed to cleanup 0 threads (count: 0, dangling: 3)
Warning -- Dangling thread: <SingleConnectionTestServerThread(preauth_data_to_tls_client, stopped 4044)>
Warning -- Dangling thread: <_MainThread(MainThread, started 620)>
Warning -- Dangling thread: <SingleConnectionTestServerThread(preauth_data_to_tls_server, stopped 2464)>
(...)
Tests result: ENV CHANGED

With this change, the test pass.

I tested my change by stressing my Windows VM:

Terminal 1 stresses the test with 4 processes: python -m test test_ssl -u all --fail-env-changed -v -m "*preauth*" -F -j4
Termainl 2 stresses the machine with 4 processes:: python -m test -j4 -r

I cannot reproduce the issue with this method on Windows anymore with this change.

vstinner

This issue also impacts Linux machines, see buildbot failures starting at this comment: #108344 (comment)

vstinner

I plan to schedule buildbot jobs on this PR to see if my fix works as expected.

I tried to write the smallest change to fix the issue, without putting # Explicitly break the reference cycle code "everywhere" (in most functions called by this test). If it's not enough, I can add even more code setting variables and attributes to None explicitly.

vstinner

On Windows x64, test_ssl failed with ENV CHANGED, but it's a different test (unrelated to this PR):

test_https_client_non_tls_response_ignored (test.test_ssl.TestPreHandshakeClose.test_https_client_non_tls_response_ignored) ...

Warning -- Uncaught thread exception: TimeoutError
Exception in thread non_tls_http_RST_responder:
Traceback (most recent call last):
  File "D:\a\cpython\cpython\Lib\threading.py", line 1059, in _bootstrap_inner
    self.run()
  File "D:\a\cpython\cpython\Lib\test\test_ssl.py", line 4708, in run
    conn, address = self.listener.accept()
                    ^^^^^^^^^^^^^^^^^^^^^^
  File "D:\a\cpython\cpython\Lib\socket.py", line 295, in accept
    fd, addr = self._accept()
               ^^^^^^^^^^^^^^
TimeoutError: timed out

bedevere-bot

🤖 New build scheduled with the buildbot fleet by @vstinner for commit ff74fd7 🤖

If you want to schedule another build, you need to add the 🔨 test-with-buildbots label again.

vstinner

Oh, on "AMD64 Fedora Stable Clang Installed PR", the bug is still there :-(

Warning -- threading_cleanup() failed to cleanup 0 threads (count: 0, dangling: 2)
Warning -- Dangling thread: <SingleConnectionTestServerThread(non_tls_http_RST_responder, stopped 140403991955136)>
Warning -- Dangling thread: <_MainThread(MainThread, started 140404254033728)>

Oh. But here, the bug occurred in test_https_client_non_tls_response_ignored().

* In preauth tests of test_ssl, explicitly break reference cycles invoving SingleConnectionTestServerThread to make sure that the thread is deleted. Otherwise, the test marks the environment as altered because the threading module sees a "dangling thread" (SingleConnectionTestServerThread). This test leak was introduced by the test added for the fix of issue pythongh-108310. * Use support.SHORT_TIMEOUT instead of hardcoded 1.0 or 2.0 seconds timeout. * SingleConnectionTestServerThread.run() catchs TimeoutError * Fix a race condition (missing synchronization) in test_preauth_data_to_tls_client(): the server now waits until the client connect() completed in call_after_accept(). * Replace socket.send() with socket.sendall() * test_https_client_non_tls_response_ignored() calls server.join() explicitly. * Replace "localhost" with server.listener.getsockname()[0].

ambv

It also still fails on Windows:

https://buildbot.python.org/all/#/builders/1088/builds/152

ambv

Maybe let's not merge this until it really fixes the issue now?

vstinner

It also still fails on Windows:

Yeah, I didn't touch test_https_client_non_tls_response_ignored() whereas this test was also fragile :-/

I rewrote my PR to make the 3 tests of TestPreHandshakeClose more reliable. The overall change is more complicated than expected, so I fixed multiple issues (more or less important).

vstinner

I stress-tested the updated PR (commit 51e1e09) on the 3 tests on Linux on Windows.

Linux:

./python -m test test_ssl -u all --fail-env-changed -m TestPreHandshakeClose -v -F -j40

Windows:

python -m test test_ssl -u all --fail-env-changed -m TestPreHandshakeClose -v -F -j10

Results:

Linux: no tests failure, 0:02:02 load avg: 39.18 [1835] test_ssl passed
Windows: no tests failure, 0:04:06 load avg: 18.28 [437] test_ssl passed

vstinner

@ambv @gpshead: Would you mind to review my change?

vstinner

Maybe let's not merge this until it really fixes the issue now?

I don't plan to merge before I'm sure that the test is very reliable :-)

gpshead

Maybe let's not merge this until it really fixes the issue now?

The challenge with these is that having an environment that the failure can be reliably reproduced in is hard. So "fixed" isn't well defined. I'm satisfied that this PR improves things and that Victor has found reproducers that appear to be healthier. But a concrete "fixed" can really only be declared after weeks of diverse buildbot data even when we're 99% confident "this is the last one for real this time".

It'd be fine to do the releases without this or the related preceeding test refleak fix PR in FWIW.

Our refleaks checks are pedantry we impose upon ourselves that also catch things that are not actual CPython bugs as is the case here.

I found and fixed a one reference cycle from the test that I saw come up during initial development. I had no way to notice or find others given I couldn't use public buildbots and I don't maintain a pile of unusually overloaded diverse OS VMs.

vstinner

The challenge with these is that having an environment that the failure can be reliably reproduced in is hard

For me, it was quite easy to reproduce the 2 issues on Windows, in a few seconds:

dangling thread on the 2 preauth tests: run the test in a loop with 4 processes for 30 seconds
dangling thread on the 3rd test: just run the test once!

Moreover, on Linux, using ./python -m test test_ssl -u all --fail-env-changed -m TestPreHandshakeClose -v -F -j40, I found another bug which required me to add server_can_continue_with_wrap_socket event.

vstinner

Right now, there are many buildbots failing on these 3 test_ssl tests because of "dangling threads" (need my fix)!

It's hard to notice that a test is not reliable in advance. In my experience, only shipping a fix and launching the heavy buildbot farm discovers race conditions in tests.

vstinner

I updated my PR to address @gpshead's review.

@gpshead @ambv: I propose that you review and approve it, and then merge it, rather than waiting for a 3rd batch of buildbot jobs on this PR.

We can use the regular buildbot process: merge the PR and then watch buildbots. Then only add backport labels to this PR once enough buildbots completed successfully.

ambv

OK, let me just run this PR branch without Greg's original fix to see if the changed tests still trigger the issue.

ambv

Yup, it still works:

======================================================================
FAIL: test_preauth_data_to_tls_client (test.test_ssl.TestPreHandshakeClose.test_preauth_data_to_tls_client)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/ubuntu/cve-2023-40217/cpython/Lib/test/test_ssl.py", line 4847, in test_preauth_data_to_tls_client
    self.assertEqual(b"", received_data)
AssertionError: b'' != b'HTTP/1.0 307 Temporary Redirect\r\nLocati[48 chars]\r\n'

======================================================================
FAIL: test_preauth_data_to_tls_server (test.test_ssl.TestPreHandshakeClose.test_preauth_data_to_tls_server)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/ubuntu/cve-2023-40217/cpython/Lib/test/test_ssl.py", line 4789, in test_preauth_data_to_tls_server
    self.assertEqual(b"", server.received_data)
AssertionError: b'' != b'DELETE /data HTTP/1.0\r\n\r\n'

----------------------------------------------------------------------
Ran 182 tests in 14.129s

gpshead

If the https cllient test still proves flaky, disabling or removing it is fine by me. (it wasn't a regression test)

vstinner

Buildbots are more happy with this change. Only one Windows Refleak buildbot still fails, just because it didn't run with the new code yet. The build 494 is running and it looks good as well ("test_ssl passed")!

…ythonGH-108370) * In preauth tests of test_ssl, explicitly break reference cycles invoving SingleConnectionTestServerThread to make sure that the thread is deleted. Otherwise, the test marks the environment as altered because the threading module sees a "dangling thread" (SingleConnectionTestServerThread). This test leak was introduced by the test added for the fix of issue pythongh-108310. * Use support.SHORT_TIMEOUT instead of hardcoded 1.0 or 2.0 seconds timeout. * SingleConnectionTestServerThread.run() catchs TimeoutError * Fix a race condition (missing synchronization) in test_preauth_data_to_tls_client(): the server now waits until the client connect() completed in call_after_accept(). * test_https_client_non_tls_response_ignored() calls server.join() explicitly. * Replace "localhost" with server.listener.getsockname()[0]. (cherry picked from commit 592bacb) Co-authored-by: Victor Stinner <vstinner@python.org>

bedevere-bot

GH-108404 is a backport of this pull request to the 3.12 branch.

…ythonGH-108370) * In preauth tests of test_ssl, explicitly break reference cycles invoving SingleConnectionTestServerThread to make sure that the thread is deleted. Otherwise, the test marks the environment as altered because the threading module sees a "dangling thread" (SingleConnectionTestServerThread). This test leak was introduced by the test added for the fix of issue pythongh-108310. * Use support.SHORT_TIMEOUT instead of hardcoded 1.0 or 2.0 seconds timeout. * SingleConnectionTestServerThread.run() catchs TimeoutError * Fix a race condition (missing synchronization) in test_preauth_data_to_tls_client(): the server now waits until the client connect() completed in call_after_accept(). * test_https_client_non_tls_response_ignored() calls server.join() explicitly. * Replace "localhost" with server.listener.getsockname()[0]. (cherry picked from commit 592bacb) Co-authored-by: Victor Stinner <vstinner@python.org>

bedevere-bot

GH-108405 is a backport of this pull request to the 3.11 branch.

…ythonGH-108370) * In preauth tests of test_ssl, explicitly break reference cycles invoving SingleConnectionTestServerThread to make sure that the thread is deleted. Otherwise, the test marks the environment as altered because the threading module sees a "dangling thread" (SingleConnectionTestServerThread). This test leak was introduced by the test added for the fix of issue pythongh-108310. * Use support.SHORT_TIMEOUT instead of hardcoded 1.0 or 2.0 seconds timeout. * SingleConnectionTestServerThread.run() catchs TimeoutError * Fix a race condition (missing synchronization) in test_preauth_data_to_tls_client(): the server now waits until the client connect() completed in call_after_accept(). * test_https_client_non_tls_response_ignored() calls server.join() explicitly. * Replace "localhost" with server.listener.getsockname()[0]. (cherry picked from commit 592bacb) Co-authored-by: Victor Stinner <vstinner@python.org>

bedevere-bot

GH-108406 is a backport of this pull request to the 3.10 branch.

…ythonGH-108370) * In preauth tests of test_ssl, explicitly break reference cycles invoving SingleConnectionTestServerThread to make sure that the thread is deleted. Otherwise, the test marks the environment as altered because the threading module sees a "dangling thread" (SingleConnectionTestServerThread). This test leak was introduced by the test added for the fix of issue pythongh-108310. * Use support.SHORT_TIMEOUT instead of hardcoded 1.0 or 2.0 seconds timeout. * SingleConnectionTestServerThread.run() catchs TimeoutError * Fix a race condition (missing synchronization) in test_preauth_data_to_tls_client(): the server now waits until the client connect() completed in call_after_accept(). * test_https_client_non_tls_response_ignored() calls server.join() explicitly. * Replace "localhost" with server.listener.getsockname()[0]. (cherry picked from commit 592bacb) Co-authored-by: Victor Stinner <vstinner@python.org>

bedevere-bot

GH-108407 is a backport of this pull request to the 3.9 branch.

…ythonGH-108370) * In preauth tests of test_ssl, explicitly break reference cycles invoving SingleConnectionTestServerThread to make sure that the thread is deleted. Otherwise, the test marks the environment as altered because the threading module sees a "dangling thread" (SingleConnectionTestServerThread). This test leak was introduced by the test added for the fix of issue pythongh-108310. * Use support.SHORT_TIMEOUT instead of hardcoded 1.0 or 2.0 seconds timeout. * SingleConnectionTestServerThread.run() catchs TimeoutError * Fix a race condition (missing synchronization) in test_preauth_data_to_tls_client(): the server now waits until the client connect() completed in call_after_accept(). * test_https_client_non_tls_response_ignored() calls server.join() explicitly. * Replace "localhost" with server.listener.getsockname()[0]. (cherry picked from commit 592bacb) Co-authored-by: Victor Stinner <vstinner@python.org>

bedevere-bot

GH-108408 is a backport of this pull request to the 3.8 branch.

…8370) (#108404) * In preauth tests of test_ssl, explicitly break reference cycles invoving SingleConnectionTestServerThread to make sure that the thread is deleted. Otherwise, the test marks the environment as altered because the threading module sees a "dangling thread" (SingleConnectionTestServerThread). This test leak was introduced by the test added for the fix of issue gh-108310. * Use support.SHORT_TIMEOUT instead of hardcoded 1.0 or 2.0 seconds timeout. * SingleConnectionTestServerThread.run() catchs TimeoutError * Fix a race condition (missing synchronization) in test_preauth_data_to_tls_client(): the server now waits until the client connect() completed in call_after_accept(). * test_https_client_non_tls_response_ignored() calls server.join() explicitly. * Replace "localhost" with server.listener.getsockname()[0]. (cherry picked from commit 592bacb) Co-authored-by: Victor Stinner <vstinner@python.org>

…8370) (#108405) * In preauth tests of test_ssl, explicitly break reference cycles invoving SingleConnectionTestServerThread to make sure that the thread is deleted. Otherwise, the test marks the environment as altered because the threading module sees a "dangling thread" (SingleConnectionTestServerThread). This test leak was introduced by the test added for the fix of issue gh-108310. * Use support.SHORT_TIMEOUT instead of hardcoded 1.0 or 2.0 seconds timeout. * SingleConnectionTestServerThread.run() catchs TimeoutError * Fix a race condition (missing synchronization) in test_preauth_data_to_tls_client(): the server now waits until the client connect() completed in call_after_accept(). * test_https_client_non_tls_response_ignored() calls server.join() explicitly. * Replace "localhost" with server.listener.getsockname()[0]. (cherry picked from commit 592bacb) Co-authored-by: Victor Stinner <vstinner@python.org>

…8370) (#108406) * In preauth tests of test_ssl, explicitly break reference cycles invoving SingleConnectionTestServerThread to make sure that the thread is deleted. Otherwise, the test marks the environment as altered because the threading module sees a "dangling thread" (SingleConnectionTestServerThread). This test leak was introduced by the test added for the fix of issue gh-108310. * Use support.SHORT_TIMEOUT instead of hardcoded 1.0 or 2.0 seconds timeout. * SingleConnectionTestServerThread.run() catchs TimeoutError * Fix a race condition (missing synchronization) in test_preauth_data_to_tls_client(): the server now waits until the client connect() completed in call_after_accept(). * test_https_client_non_tls_response_ignored() calls server.join() explicitly. * Replace "localhost" with server.listener.getsockname()[0]. (cherry picked from commit 592bacb) Co-authored-by: Victor Stinner <vstinner@python.org>

) (#108407) * In preauth tests of test_ssl, explicitly break reference cycles invoving SingleConnectionTestServerThread to make sure that the thread is deleted. Otherwise, the test marks the environment as altered because the threading module sees a "dangling thread" (SingleConnectionTestServerThread). This test leak was introduced by the test added for the fix of issue gh-108310. * Use support.SHORT_TIMEOUT instead of hardcoded 1.0 or 2.0 seconds timeout. * SingleConnectionTestServerThread.run() catchs TimeoutError * Fix a race condition (missing synchronization) in test_preauth_data_to_tls_client(): the server now waits until the client connect() completed in call_after_accept(). * test_https_client_non_tls_response_ignored() calls server.join() explicitly. * Replace "localhost" with server.listener.getsockname()[0]. (cherry picked from commit 592bacb) Co-authored-by: Victor Stinner <vstinner@python.org>

) (#108408) * In preauth tests of test_ssl, explicitly break reference cycles invoving SingleConnectionTestServerThread to make sure that the thread is deleted. Otherwise, the test marks the environment as altered because the threading module sees a "dangling thread" (SingleConnectionTestServerThread). This test leak was introduced by the test added for the fix of issue gh-108310. * Use support.SHORT_TIMEOUT instead of hardcoded 1.0 or 2.0 seconds timeout. * SingleConnectionTestServerThread.run() catchs TimeoutError * Fix a race condition (missing synchronization) in test_preauth_data_to_tls_client(): the server now waits until the client connect() completed in call_after_accept(). * test_https_client_non_tls_response_ignored() calls server.join() explicitly. * Replace "localhost" with server.listener.getsockname()[0]. (cherry picked from commit 592bacb)

…ythonGH-108370) (python#108407) * In preauth tests of test_ssl, explicitly break reference cycles invoving SingleConnectionTestServerThread to make sure that the thread is deleted. Otherwise, the test marks the environment as altered because the threading module sees a "dangling thread" (SingleConnectionTestServerThread). This test leak was introduced by the test added for the fix of issue pythongh-108310. * Use support.SHORT_TIMEOUT instead of hardcoded 1.0 or 2.0 seconds timeout. * SingleConnectionTestServerThread.run() catchs TimeoutError * Fix a race condition (missing synchronization) in test_preauth_data_to_tls_client(): the server now waits until the client connect() completed in call_after_accept(). * test_https_client_non_tls_response_ignored() calls server.join() explicitly. * Replace "localhost" with server.listener.getsockname()[0]. (cherry picked from commit 592bacb) Co-authored-by: Victor Stinner <vstinner@python.org>

bedevere-bot added the tests Tests in the Lib/test dir label Aug 23, 2023

bedevere-bot mentioned this pull request Aug 23, 2023

test_ssl fails with "env changed" on ARM64 Windows buildbot: thread doesn't catch TimeoutError #108342

Closed

2 tasks

bedevere-bot added the awaiting core review label Aug 23, 2023

vstinner added the skip news label Aug 23, 2023

vstinner added the 🔨 test-with-buildbots Test PR w/ buildbots; report in status section label Aug 23, 2023

bedevere-bot removed the 🔨 test-with-buildbots Test PR w/ buildbots; report in status section label Aug 23, 2023

vstinner mentioned this pull request Aug 23, 2023

gh-108342: Break ref cycle in SSLSocket._create() exc #108344

Merged

gpshead approved these changes Aug 23, 2023

View reviewed changes

bedevere-bot added awaiting merge and removed awaiting core review labels Aug 23, 2023

vstinner force-pushed the test_ssl_preauth branch from ff74fd7 to 51e1e09 Compare August 23, 2023 18:55

vstinner mentioned this pull request Aug 23, 2023

gh-108314: Add PyDict_ContainsString() function #108323

Merged

vstinner changed the title ~~gh-108342: Break ref cycle in test_ssl preauth~~ Aug 23, 2023

ambv reviewed Aug 23, 2023

View reviewed changes

Address Gregory's review

c62c680

correct comment text.

16149b2

ambv approved these changes Aug 23, 2023

View reviewed changes

bedevere-bot added awaiting merge and removed awaiting changes labels Aug 23, 2023

gpshead approved these changes Aug 23, 2023

View reviewed changes

vstinner enabled auto-merge (squash) August 23, 2023 21:35

vstinner merged commit 592bacb into python:main Aug 23, 2023

bedevere-bot removed the awaiting merge label Aug 23, 2023

vstinner deleted the test_ssl_preauth branch August 23, 2023 22:00

Conversation

vstinner commented Aug 23, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

vstinner commented Aug 23, 2023

Uh oh!

vstinner commented Aug 23, 2023

Uh oh!

vstinner commented Aug 23, 2023

Uh oh!

vstinner commented Aug 23, 2023

Uh oh!

bedevere-bot commented Aug 23, 2023

Uh oh!

vstinner commented Aug 23, 2023

Uh oh!

ambv commented Aug 23, 2023

Uh oh!

ambv commented Aug 23, 2023

Uh oh!

vstinner commented Aug 23, 2023

Uh oh!

vstinner commented Aug 23, 2023

Uh oh!

vstinner commented Aug 23, 2023

Uh oh!

vstinner commented Aug 23, 2023

Uh oh!

gpshead commented Aug 23, 2023

Uh oh!

vstinner commented Aug 23, 2023

Uh oh!

vstinner commented Aug 23, 2023

Uh oh!

vstinner commented Aug 23, 2023

Uh oh!

ambv commented Aug 23, 2023

Uh oh!

ambv commented Aug 23, 2023

Uh oh!

gpshead left a comment

Choose a reason for hiding this comment

Uh oh!

vstinner commented Aug 24, 2023

Uh oh!

bedevere-bot commented Aug 24, 2023

Uh oh!

bedevere-bot commented Aug 24, 2023

Uh oh!

bedevere-bot commented Aug 24, 2023

Uh oh!

bedevere-bot commented Aug 24, 2023

Uh oh!

bedevere-bot commented Aug 24, 2023

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants

vstinner commented Aug 23, 2023 •

edited

Loading