Repository navigation
SSL session content bleeds into stdout with lots of threads #118138
Description
Bug report
Bug description:
I've been trying to track down a rare segfault I'm seeing with Python 3 (several versions) in AWS Lambda and AWS CodeBuild. It's been very hard to reproduce, but I have a few stack traces that show the crash happens in OpenSSL's certificate verification code below Python's ssl module. While trying to isolate the problem in OpenSSL, I stumbled on a different issue that might be related, which I'm reporting here.
The program below uses the standard library to execute a lot of HTTPS requests concurrently with threads. When run on my Linux desktop in gnome-terminal, the program doesn't exhibit any weird behavior. It prints a bunch of X characters for each request it completes. However, if I pipe its output through a program like less or tee, I see additional output--raw bytes from the SSL network session bleeding into stdout. It feels like OpenSSL is writing into memory that Python's using to prepare strings or print to stdout due to a lack of synchronization or refcounting, but I don't know OpenSSL or Python internals well, so this is just a guess.
python3 test-program.py | tee /dev/null makes it happen every time on my workstation. It never crashes, it just bleeds SSL contents into the output.
It happens on Ubuntu 22.04 x86_64 with Python 3.12 and OpenSSL 3.0.2, and on AWS CloudShell with Python 3.9.16 and OpenSSL 3.0.8.
Feel free to run this program as often as you want with the URL I put in there (it's a small static web page on my personal site that won't mind a few thousand hits).
#!/usr/bin/env python3
import http.client
import logging
from concurrent.futures import ThreadPoolExecutor
from ssl import create_default_context, Purpose
from threading import Barrier
logger = logging.getLogger(__name__)
# Point this at your system's CA cert store.
CERT_FILE = '/tmp/cacert.pem'
# The problem reproduces reliably with 100 threads for me, and
# with more threads it happens even more times per execution.
#
# It also happens with a small number of threads (like 10) if
# you make do_one_request process lots of requests instead of one.
NUM_THREADS = 200
# The barrier is helpful for getting all the requests lined up
# to start together. The problem still happens without a barrier
# if you run lots of requests in each thread instead of one.
b = Barrier(NUM_THREADS)
def do_one_request():
try:
# SSLContext is supposed to be thread-safe, but I allocate a new
# one each time to rule out concurrent access to it being the problem.
ssl_context = create_default_context(purpose=Purpose.SERVER_AUTH, cafile=CERT_FILE)
b.wait()
# Do a simple request and close the connection. This URL is a small
# static page behind AWS CloudFront owned by the bug reporter, so
# don't feel bad about sending a few thousand requests there. The
# bug seems to happen with any valid HTTPS request.
c = http.client.HTTPSConnection('tinfig.com', context=ssl_context)
c.request('GET', 'https://tinfig.com/')
_ = c.getresponse()
c.close()
# Print enough output so a pager or reading process might have to buffer.
print(' ' + ('X' * 200))
except Exception as e:
logger.exception(e)
with ThreadPoolExecutor(max_workers=NUM_THREADS) as executor:
for i in range(NUM_THREADS):
executor.submit(do_one_request)
executor.shutdown(wait=True)CPython versions tested on:
3.9, 3.12
Operating systems tested on:
Linux
Activity
sterwill commentedon Apr 21, 2024
I built Python 3.12.3 --with-pydebug, and now I get a crash before any corrupt output shows. Backtrace from gdb (happy to provide more if it would be helpful):
elistevens commentedon May 15, 2024
We are seeing a similar issue (
python: external/python3.10/Modules/_io/textio.c:1597: _textiowrapper_writeflush: Assertionpos == self->pending_bytes_count' failed.` in a built-in-house debug build of python).No repro for it from our side, since it's happening intermittently in a fairly complicated Ray program, so we haven't tried to minimize the issue. Just wanted to note that users unaffiliated with @sterwill are seeing the issue as well.
elistevens commentedon May 16, 2024
https://github.com/python/cpython/blob/3.10/Modules/_io/textio.c#L1584 calls
PyUnicode_DATAandPyUnicode_GET_LENGTH. https://docs.python.org/3/c-api/unicode.html#c.PyUnicode_GET_LENGTH says "Return the length of the Unicode string, in code points. unicode has to be a Unicode object in the “canonical” representation (not checked)."Any idea what the canonical representation is, and/or how to check it?
Applying the following patch to python 3.10.12
Produces this output for a failing case:
The length 0 entries seem suspicious to me.
While anecdotal, the issue seems to happen more often for me when I enable TQDM-style progress bars. I'm not sure if that's A) true, B) related to the code paths used like https://github.com/python/cpython/blob/3.10/Modules/_io/textio.c#L1663 , or C) just due to there being a lot more output when I do so.
elistevens commentedon May 16, 2024
FYI I am able to reproduce the problem reliably with the following reduced script:
I've added slightly more debugging output to the above patch, and am now getting output like:
142 entries / 2 writes per print * (99 'x' + 1 '\n') == 7100, so I think that the zero-length entry I mentioned above probably isn't relevant. Why it's expecting 8100 bytes and not 100k isn't clear to me.
Interestingly, it always comes up as 7100 vs. 8100. Without the barrier it varied more, but the few times I ran it it was only no error, 800 vs. 8100, or 7100 vs. 8100.
My guess at this point is that there's a threading issue with appending to and clearing the list, but I'm getting out of my depth.
elistevens commentedon May 16, 2024
I have increased confidence that it's a threading issue now. With this patch:
The above script produces this on stderr:
Almost certainly some other thread is coming in and adding some list entries which would then get overwritten by that
self->pending_bytes = b;line.I have also confirmed that the stdout from the script is missing some expected output (I changed the "xxxx" to be the i, j of the thread and inner loop, and some of those go missing).
elistevens commentedon May 17, 2024
This patch fixes the issue for me on python 3.10.12, but not on
main(3.14.0a0).This is probably an awful way to fix the issue.
Adds test for multithreaded writes to files.
duaneg commentedon May 30, 2025
I cannot reproduce the bug on current HEAD (v3.15-alpha): possibly it was fixed by #119506 or related changes? Although I wasn't able to reproduce a crash with the commit prior to that change either...
While investigating this I did find a different-but-related bug in free threading builds, as
textiowrapper_iternextcalls_textiowrapper_writeflushbut is not protected by a critical section. I've opened a separate issue for that (#134908).picnixz commentedon Oct 25, 2025
Closing since the bug cannot be reproduced (I cannot reproduce it on main with the given reproducer).