Skip to content

Crash when concurrently writing with print and concurrently modifying sys.stdout #130163

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
devdanzin opened this issue Feb 15, 2025 · 40 comments
Closed
Labels
interpreter-core (Objects, Python, Grammar, and Parser dirs) topic-C-API type-crash A hard crash of the interpreter, possibly with a core dump

Comments

@devdanzin
Copy link
Contributor

devdanzin commented Feb 15, 2025

Crash report

What happened?

Playing with the code from #130148, I stumbled on a segfault in a free-threaded debug build with the following (seems to trigger faster/more consistently when pasted in the REPL):

from contextlib import redirect_stdout
from io import StringIO
from threading import Thread
import time


def test_redirect():
    text = StringIO()
    with redirect_stdout(text):
        print("hello1", file=text)
        time.sleep(0.1)
        print("hello2", file=text)
    print(text.getvalue())
    assert text.getvalue() == "hello1\nhello2\n"


for x in range(100):
    Thread(target=test_redirect, args=()).start()

I didn't have time to check whether JIT, debug or no-gil are strictly necessary for this to crash. JIT is not needed for this to crash.

Cause

The problem is that in the print() implementation, _PySys_GetAttr returns a borrowed reference.

cpython/Python/bltinmodule.c

Lines 2173 to 2175 in 655fc8a

if (file == Py_None) {
PyThreadState *tstate = _PyThreadState_GET();
file = _PySys_GetAttr(tstate, &_Py_ID(stdout));

So if sys.stdout changes concurrently with the print(), the program may crash because file will point to a deallocated Python object.

This affects the GIL-enabled build as well. See this reproducer: https://gist.github.com/colesbury/c48f50e95d5d68e24814a56e2664e587

Suggested fix

Introduce a _PySys_GetAttrRef that returns a new reference instead of a borrowed reference. Use that instead.

We should audit all the uses of _PySys_GetAttr and PySys_GetObject. I expect most of them will need to be replaced with functions that return new references, but it doesn't all have to be in a single PR.

CPython versions tested on:

CPython main branch

Operating systems tested on:

Linux

Output from running 'python -VV' on the command line:

Python 3.14.0a5+ experimental free-threading build (heads/main:359c7dde3bb, Feb 15 2025, 17:54:11) [GCC 11.4.0]

Linked PRs

@devdanzin devdanzin added the type-crash A hard crash of the interpreter, possibly with a core dump label Feb 15, 2025
@devdanzin devdanzin changed the title Segfault in a freethreaded JIT build from using contextlib.redirect_stdout in threads Segfault in a freethreaded build from using contextlib.redirect_stdout in threads Feb 15, 2025
@tomasr8 tomasr8 removed the topic-JIT label Feb 15, 2025
@picnixz
Copy link
Member

picnixz commented Feb 15, 2025

The issue could be with StringIO() or sys.stdout/sys.stderr or with context managers in general. I don't know where to start to investigate this =/

@tomasr8
Copy link
Member

tomasr8 commented Feb 15, 2025

Here's the backtrace:

#0  PyObject_GetAttr (v=v@entry=0x2002c0f00d0, name=0x555555b83358 <_PyRuntime+110680>) at Objects/object.c:1288
#1  0x0000555555688162 in PyFile_WriteObject (v=v@entry=0x555555b836e0 <_PyRuntime+111584>, f=f@entry=0x2002c0f00d0, flags=flags@entry=1) at Objects/fileobject.c:113
#2  0x0000555555688279 in PyFile_WriteString (s=s@entry=0x5555558efa49 "\n", f=f@entry=0x2002c0f00d0) at Objects/fileobject.c:149
#3  0x000055555579c917 in builtin_print_impl (module=module@entry=0x2000025c5d0, args=args@entry=0x7fffd4bffb78, args_length=args_length@entry=1, sep=0x0, sep@entry=0x555555b410a0 <_Py_NoneStruct>, end=0x0, end@entry=0x555555b410a0 <_Py_NoneStruct>, file=0x2002c0f00d0, file@entry=0x555555b410a0 <_Py_NoneStruct>, flush=0) at Python/bltinmodule.c:2222
#4  0x000055555579ca97 in builtin_print (module=0x2000025c5d0, args=args@entry=0x7fffd4bffb78, nargs=nargs@entry=1, kwnames=kwnames@entry=0x0) at Python/clinic/bltinmodule.c.h:985
#5  0x00005555556c245b in cfunction_vectorcall_FASTCALL_KEYWORDS (func=0x2000025d670, args=0x7fffd4bffb78, nargsf=<optimized out>, kwnames=0x0) at Objects/methodobject.c:452
#6  0x0000555555667519 in _PyObject_VectorcallTstate (tstate=0x555555cb4900, callable=callable@entry=0x2000025d670, args=args@entry=0x7fffd4bffb78, nargsf=9223372036854775809, kwnames=kwnames@entry=0x0) at ./Include/internal/pycore_call.h:167
#7  0x00005555556675f5 in PyObject_Vectorcall (callable=callable@entry=0x2000025d670, args=args@entry=0x7fffd4bffb78, nargsf=<optimized out>, kwnames=kwnames@entry=0x0) at Objects/call.c:327
#8  0x00005555557abdd3 in _PyEval_EvalFrameDefault (tstate=<optimized out>, frame=0x7ffff7e3d1b0, throwflag=<optimized out>) at Python/generated_cases.c.h:1371
#9  0x00005555557d0ca5 in _PyEval_EvalFrame (tstate=tstate@entry=0x555555cb4900, frame=frame@entry=0x7ffff7e3d020, throwflag=throwflag@entry=0) at ./Include/internal/pycore_ceval.h:116
#10 0x00005555557d0e76 in _PyEval_Vector (tstate=0x555555cb4900, func=0x2000068dc90, locals=locals@entry=0x0, args=0x7fffd4bffd48, argcount=<optimized out>, kwnames=0x0) at Python/ceval.c:1745
#11 0x0000555555667192 in _PyFunction_Vectorcall (func=<optimized out>, stack=<optimized out>, nargsf=<optimized out>, kwnames=<optimized out>) at Objects/call.c:413
#12 0x000055555566a435 in _PyObject_VectorcallTstate (tstate=tstate@entry=0x555555cb4900, callable=callable@entry=0x2000068dc90, args=args@entry=0x7fffd4bffd48, nargsf=nargsf@entry=1, kwnames=kwnames@entry=0x0) at ./Include/internal/pycore_call.h:167
#13 0x000055555566a69a in method_vectorcall (method=<optimized out>, args=0x555555b87c98 <_PyRuntime+129432>, nargsf=0, kwnames=0x0) at Objects/classobject.c:72
#14 0x0000555555668e22 in _PyVectorcall_Call (tstate=tstate@entry=0x555555cb4900, func=0x55555566a4bd <method_vectorcall>, callable=callable@entry=0x200006b8170, tuple=tuple@entry=0x555555b87c70 <_PyRuntime+129392>, kwargs=kwargs@entry=0x0) at Objects/call.c:273
#15 0x0000555555669151 in _PyObject_Call (tstate=0x555555cb4900, callable=0x200006b8170, args=0x555555b87c70 <_PyRuntime+129392>, kwargs=0x0) at Objects/call.c:348
#16 0x000055555566918d in PyObject_Call (callable=<optimized out>, args=<optimized out>, kwargs=<optimized out>) at Objects/call.c:373
#17 0x00005555558cf626 in thread_run (boot_raw=boot_raw@entry=0x555555cb48b0) at ./Modules/_threadmodule.c:354
#18 0x000055555585b7f3 in pythread_wrapper (arg=<optimized out>) at Python/thread_pthread.h:242
#19 0x00007ffff7c9caa4 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:447
#20 0x00007ffff7d29c3c in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:78

The immediate cause seems to be related to the printing itself, but I didn't dig into it too much

@devdanzin
Copy link
Contributor Author

The issue could be with StringIO() or sys.stdout/sys.stderr or with context managers in general.

Substituting StringIO with the following stops crashing, would it point to it being the culprit?

class FakeStringIO:
    def write(self, value):
        pass
    def getvalue(self):
        return "hello1\nhello2\n"
    def flush(self):
        pass

@picnixz
Copy link
Member

picnixz commented Feb 15, 2025

I suspect it has something to do with the PyFile_* interface.

@tomasr8
Copy link
Member

tomasr8 commented Feb 15, 2025

Might be something to do with redirect_stdout, I'm getting a segfault even with this simplified reproducer:

from contextlib import redirect_stdout
from io import StringIO
from threading import Thread
import time


def test_redirect():
    text = StringIO()
    with redirect_stdout(text):
        time.sleep(0.1)
    print(text.getvalue())


for x in range(100):
    Thread(target=test_redirect, args=()).start()

edit:

Both crashes seem to be caused by Py_TYPE returning NULL. Here's the backtrace for this repro:

#0  _Py_Dealloc (op=op@entry=0x2009c1000d0) at Objects/object.c:2994
#1  0x00005555556c8407 in _Py_DecRefSharedDebug (o=o@entry=0x2009c1000d0, filename=filename@entry=0x5555558e4237 "./Include/refcount.h", lineno=lineno@entry=502) at Objects/object.c:418
#2  0x00005555556c2569 in Py_DECREF (filename=filename@entry=0x5555558e4237 "./Include/refcount.h", lineno=lineno@entry=502, op=0x2009c1000d0) at ./Include/refcount.h:347
#3  0x00005555556c28bb in Py_XDECREF (op=<optimized out>) at ./Include/refcount.h:502
#4  0x00005555556c2ff1 in meth_dealloc (self=0x2009e0e0160) at Objects/methodobject.c:172
#5  0x00005555556c82fe in _Py_Dealloc (op=0x2009e0e0160) at Objects/object.c:3014
#6  0x00005555556c83d7 in _Py_MergeZeroLocalRefcount (op=op@entry=0x2009e0e0160) at Objects/object.c:436
#7  0x000055555568767f in Py_DECREF (filename=filename@entry=0x5555558eb2c2 "Objects/fileobject.c", lineno=lineno@entry=127, op=op@entry=0x2009e0e0160) at ./Include/refcount.h:343
#8  0x00005555556881c1 in PyFile_WriteObject (v=v@entry=0x555555b836e0 <_PyRuntime+111584>, f=f@entry=0x2009c1000d0, flags=flags@entry=1) at Objects/fileobject.c:127
#9  0x0000555555688279 in PyFile_WriteString (s=s@entry=0x5555558efa49 "\n", f=f@entry=0x2009c1000d0) at Objects/fileobject.c:149
#10 0x000055555579c917 in builtin_print_impl (module=module@entry=0x2000025c5d0, args=args@entry=0x7fff5f3ffb78, args_length=args_length@entry=1, sep=0x0, sep@entry=0x555555b410a0 <_Py_NoneStruct>, end=0x0, end@entry=0x555555b410a0 <_Py_NoneStruct>, file=0x2009c1000d0, file@entry=0x555555b410a0 <_Py_NoneStruct>, flush=0) at Python/bltinmodule.c:2222
#11 0x000055555579ca97 in builtin_print (module=0x2000025c5d0, args=args@entry=0x7fff5f3ffb78, nargs=nargs@entry=1, kwnames=kwnames@entry=0x0) at Python/clinic/bltinmodule.c.h:985
#12 0x00005555556c245b in cfunction_vectorcall_FASTCALL_KEYWORDS (func=0x2000025d670, args=0x7fff5f3ffb78, nargsf=<optimized out>, kwnames=0x0) at Objects/methodobject.c:452
#13 0x0000555555667519 in _PyObject_VectorcallTstate (tstate=0x555555daaa30, callable=callable@entry=0x2000025d670, args=args@entry=0x7fff5f3ffb78, nargsf=9223372036854775809, kwnames=kwnames@entry=0x0) at ./Include/internal/pycore_call.h:167
#14 0x00005555556675f5 in PyObject_Vectorcall (callable=callable@entry=0x2000025d670, args=args@entry=0x7fff5f3ffb78, nargsf=<optimized out>, kwnames=kwnames@entry=0x0) at Objects/call.c:327
#15 0x00005555557abdd3 in _PyEval_EvalFrameDefault (tstate=<optimized out>, frame=0x7ffff75641b0, throwflag=<optimized out>) at Python/generated_cases.c.h:1371
#16 0x00005555557d0ca5 in _PyEval_EvalFrame (tstate=tstate@entry=0x555555daaa30, frame=frame@entry=0x7ffff7564020, throwflag=throwflag@entry=0) at ./Include/internal/pycore_ceval.h:116
#17 0x00005555557d0e76 in _PyEval_Vector (tstate=0x555555daaa30, func=0x2000068dc90, locals=locals@entry=0x0, args=0x7fff5f3ffd48, argcount=<optimized out>, kwnames=0x0) at Python/ceval.c:1745
#18 0x0000555555667192 in _PyFunction_Vectorcall (func=<optimized out>, stack=<optimized out>, nargsf=<optimized out>, kwnames=<optimized out>) at Objects/call.c:413
#19 0x000055555566a435 in _PyObject_VectorcallTstate (tstate=tstate@entry=0x555555daaa30, callable=callable@entry=0x2000068dc90, args=args@entry=0x7fff5f3ffd48, nargsf=nargsf@entry=1, kwnames=kwnames@entry=0x0) at ./Include/internal/pycore_call.h:167
#20 0x000055555566a69a in method_vectorcall (method=<optimized out>, args=0x555555b87c98 <_PyRuntime+129432>, nargsf=0, kwnames=0x0) at Objects/classobject.c:72
#21 0x0000555555668e22 in _PyVectorcall_Call (tstate=tstate@entry=0x555555daaa30, func=0x55555566a4bd <method_vectorcall>, callable=callable@entry=0x200006babd0, tuple=tuple@entry=0x555555b87c70 <_PyRuntime+129392>, kwargs=kwargs@entry=0x0) at Objects/call.c:273
#22 0x0000555555669151 in _PyObject_Call (tstate=0x555555daaa30, callable=0x200006babd0, args=0x555555b87c70 <_PyRuntime+129392>, kwargs=0x0) at Objects/call.c:348
#23 0x000055555566918d in PyObject_Call (callable=<optimized out>, args=<optimized out>, kwargs=<optimized out>) at Objects/call.c:373
#24 0x00005555558cf626 in thread_run (boot_raw=boot_raw@entry=0x555555daa9e0) at ./Modules/_threadmodule.c:354
#25 0x000055555585b7f3 in pythread_wrapper (arg=<optimized out>) at Python/thread_pthread.h:242
#26 0x00007ffff7c9caa4 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:447
#27 0x00007ffff7d29c3c in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:78

@picnixz
Copy link
Member

picnixz commented Feb 15, 2025

Might be something to do with redirect_stdout, I'm getting a segfault even with this simplified reproducer:

Have you tried removing the usage to StringIO()? because it appears that we crash in Py_DECREF of a file object.

@sergey-miryanov
Copy link
Contributor

sergey-miryanov commented Feb 16, 2025

Yes, it is caused by redirect_stdout.

  1. At some point, print from T1 and T2 uses StringIO, which is owned by T1.
  2. PyObject_GetAttr (
    writer = PyObject_GetAttr(f, &_Py_ID(write));
    ) increments shared ref_cnt (by T2) and local ref_cnt (by T1).
  3. Py_DECREF (
    Py_DECREF(writer);
    ) from T2 decrements shared ref_cnt and got 0 and do _Py_Dealloc
  4. Py_DECREF from T1 decrements local ref_cnt, got 0 and go to _Py_MergeZeroLocalRefcount, see that shared ref_cnt is 0 and go to fast path and do _Py_Dealloc.
  5. This is double free and so segfault.

The easiest way to fix this is probably to protect PyFile_WriteObject with a critical section. However, this might slightly affect the performance of single-threaded apps.

The best solution might be to update the documentation and point out this potential issue with redirect_*.

@devdanzin
Copy link
Contributor Author

Have you tried removing the usage to StringIO()?

Using open("/dev/null", "w") instead of StringIO still segfaults.

Yes, it is caused by redirect_stdout.

But any program that does redirect_stdout does will also segfault:

from threading import Thread
import sys
import time


def test_redirect():
    text = open("/dev/null", "w")
    old_stdout = sys.stdout
    sys.stdout = text
    print("hello1")
    time.sleep(0.3)
    print("hello2")
    sys.stdout = old_stdout


for x in range(200):
    Thread(target=test_redirect, args=()).start()

The easiest way to fix this is probably to protect PyFile_WriteObject with a critical section. However, this might slightly affect the performance of single-threaded apps.

Would making the presence of the critical section dependent on whether the build is freethreaded (and/or the GIL is disabled) avoid the performance impact for gilfull builds? Or would it be a bad idea to have this conditional difference in behavior?

The best solution might be to update the documentation and point out this potential issue with redirect_*.

ISTM that fixing the segfault is necessary, even if a note is added to docs, because users may hit the segfault without using redirect_*.

@picnixz
Copy link
Member

picnixz commented Feb 16, 2025

Yes it's not redirect_stdout that is the culprit, it's the PyFile API.

@picnixz picnixz added interpreter-core (Objects, Python, Grammar, and Parser dirs) and removed stdlib Python modules in the Lib dir labels Feb 16, 2025
@devdanzin
Copy link
Contributor Author

devdanzin commented Feb 16, 2025

It's much harder to segfault in a non-debug build. There are many ValueError: I/O operation on uninitialized object and ValueError: I/O operation on uninitialized object errors when running. Here's a Fatal Python error that may happen in such a build:

Objects/object.c:578: PyObject_CallFinalizerFromDealloc: Assertion failed: PyObject_CallFinalizerFromDealloc called on object with a non-zero refcount
Enable tracemalloc to get the memory block allocation traceback

object address  : 0x5e31e1700e0
object refcount : 1
object type     : 0x5e2ae298200
object type name: _io.TextIOWrapper
object repr     : <_io.TextIOWrapper name='/dev/null' mode='w' encoding='UTF-8'>

Fatal Python error: _PyObject_AssertFailed: _PyObject_AssertFailed
Python runtime state: initialized

Edit: of course, just after I posted this comment, a segfault in a non-debug build happened:

#0  __new_sem_post (sem=0x0) at ./nptl/sem_post.c:35
#1  0x00005555558758ed in PyThread_release_lock (
    lock=<optimized out>)
    at Python/thread_pthread.h:618
#2  0x00005555558c7921 in _io__Buffered_close_impl (
    self=0x3365e1f00c0)
    at ./Modules/_io/bufferedio.c:596
#3  _io__Buffered_close (
    self=<_io.BufferedWriter at remote 0x3365e1f00c0>,
    _unused_ignored=<optimized out>)
    at ./Modules/_io/clinic/bufferedio.c.h:375
#4  0x0000555555654b83 in method_vectorcall_NOARGS (
    func=<method_descriptor at remote 0x335fe3d6130>,
    args=0x7ffe6fdff7e8, nargsf=<optimized out>,
    kwnames=0x0) at Objects/descrobject.c:447
#5  0x000055555564184e in _PyObject_VectorcallTstate (
    tstate=0x555555e53bb0,
    callable=<method_descriptor at remote 0x335fe3d6130>, args=0x7ffe6fdff7e8, nargsf=<optimized out>,
    kwnames=0x0)
    at ./Include/internal/pycore_call.h:167
    args=args@entry=0x7ffe6fdff7e8, nargsf=<optimized out>, nargsf@entry=9223372036854775809,
    kwnames=kwnames@entry=0x0) at Objects/call.c:856
#7  0x00005555558cf1c0 in PyObject_CallMethodNoArgs (self=<optimized out>,
    name=<optimized out>) at ./Include/cpython/abstract.h:65
#8  _io_TextIOWrapper_close_impl (self=0x3365e2000e0) at ./Modules/_io/textio.c:3167
#9  _io_TextIOWrapper_close (self=<_io.TextIOWrapper at remote 0x3365e2000e0>,
    _unused_ignored=<optimized out>) at ./Modules/_io/clinic/textio.c.h:1138
#10 0x0000555555654b83 in method_vectorcall_NOARGS (
    func=<method_descriptor at remote 0x335fe3d8890>, args=0x7ffe6fdff8d0,
    nargsf=<optimized out>, kwnames=0x0) at Objects/descrobject.c:447
#11 0x000055555564184e in _PyObject_VectorcallTstate (tstate=0x555555e53bb0,
    callable=<method_descriptor at remote 0x335fe3d8890>, args=0x7ffe6fdff8d0,
    nargsf=<optimized out>, kwnames=0x0) at ./Include/internal/pycore_call.h:167
#12 PyObject_VectorcallMethod (name=<optimized out>, args=args@entry=0x7ffe6fdff8d0,
    nargsf=<optimized out>, nargsf@entry=9223372036854775809, kwnames=kwnames@entry=0x0)
    at Objects/call.c:856
#13 0x00005555558bebad in PyObject_CallMethodNoArgs (self=<optimized out>,
    name=<optimized out>) at ./Include/cpython/abstract.h:65
#14 iobase_finalize (self=<_io.TextIOWrapper at remote 0x3365e2000e0>)
    at ./Modules/_io/iobase.c:317
#15 0x00005555556bf3a0 in PyObject_CallFinalizer (
    self=<_io.TextIOWrapper at remote 0x3365e2000e0>) at Objects/object.c:568
#16 0x00005555556c5dfc in PyObject_CallFinalizerFromDealloc (
    self=self@entry=<_io.TextIOWrapper at remote 0x3365e2000e0>) at Objects/object.c:586
#17 0x00005555558bfd4e in _PyIOBase_finalize (
    self=self@entry=<_io.TextIOWrapper at remote 0x3365e2000e0>) at ./Modules/_io/iobase.c:340
#18 0x00005555558ce6ca in textiowrapper_dealloc (
    op=<_io.TextIOWrapper at remote 0x3365e2000e0>) at ./Modules/_io/textio.c:1468
#19 0x00005555556a8ebd in Py_XDECREF (op=<optimized out>) at ./Include/refcount.h:502
#20 insertdict (mp=0x335fe01a600, key='stdout', hash=-9074624609838634197,
    value=<_io.TextIOWrapper(mode='w') at remote 0x3375a1f00e0>, interp=<optimized out>)
    at Objects/dictobject.c:1864
#21 0x00005555556aae68 in _PyObjectDict_SetItem (tp=tp@entry=0x555555b023a0 <PyModule_Type>,
    obj=obj@entry=<module at remote 0x335fe25e060>, dictptr=<optimized out>,
    key=key@entry='stdout',
    value=value@entry=<_io.TextIOWrapper(mode='w') at remote 0x3375a1f00e0>)
    at Objects/dictobject.c:7502
#22 0x00005555556c3add in _PyObject_GenericSetAttrWithDict (
    obj=<module at remote 0x335fe25e060>, name='stdout',
    value=<_io.TextIOWrapper(mode='w') at remote 0x3375a1f00e0>, dict=0x0)
    at Objects/object.c:1853
#23 0x00005555556c150c in PyObject_SetAttr (v=v@entry=<module at remote 0x335fe25e060>,
    name=<optimized out>,
    value=value@entry=<_io.TextIOWrapper(mode='w') at remote 0x3375a1f00e0>)
    at Objects/object.c:1443
#24 0x00005555557d2701 in _PyEval_EvalFrameDefault (tstate=<optimized out>,
    frame=<optimized out>, throwflag=<optimized out>)
    at ./Include/internal/pycore_stackref.h:184
#25 0x00005555557dcf6e in _PyEval_EvalFrame (tstate=0x555555e53bb0, frame=<optimized out>,
    throwflag=0) at ./Include/internal/pycore_ceval.h:116
#26 _PyEval_Vector (tstate=0x555555e53bb0, func=0x335fe4f48c0, locals=0x0,
    args=<optimized out>, argcount=1, kwnames=<optimized out>) at Python/ceval.c:1745
#27 0x00005555556445c3 in _PyObject_VectorcallTstate (tstate=0x555555e53bb0,
    callable=<function at remote 0x335fe4f48c0>, args=0x7ffe6fdffe18, nargsf=1, kwnames=0x0)
    at ./Include/internal/pycore_call.h:167
#28 method_vectorcall (method=<optimized out>, args=0x555555b45450 <_PyRuntime+113424>,
    nargsf=<optimized out>, kwnames=0x0) at Objects/classobject.c:72
#29 0x00005555558fa480 in thread_run (boot_raw=0x555555e53b70)
    at ./Modules/_threadmodule.c:354
#30 0x000055555587508b in pythread_wrapper (arg=<optimized out>)
    at Python/thread_pthread.h:242
#31 0x00007ffff7ca1e2e in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:447
#32 0x00007ffff7d33a4c in __GI___clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:78

Is it a different crash?

@sergey-miryanov
Copy link
Contributor

Try to acquire CS before

writer = PyObject_GetAttr(f, &_Py_ID(write));
and release after
Py_DECREF(writer);
and segfault should gone.

@picnixz
Copy link
Member

picnixz commented Feb 16, 2025

Is it a different crash?

Ok, it's perhaps not the PyFile API, but just the buffer API itself. To check this, can you try no using print but directly use .write of the io wrapper?

@picnixz
Copy link
Member

picnixz commented Feb 16, 2025

Ok, I couldn't manage to make it crash with a pure buffer API, so it's likely the print() itself.

@picnixz
Copy link
Member

picnixz commented Feb 16, 2025

Even with a critical section, I still get a segfault:

diff --git a/Objects/fileobject.c b/Objects/fileobject.c
index 7025b5bcffc..7b84f5962fe 100644
--- a/Objects/fileobject.c
+++ b/Objects/fileobject.c
@@ -3,6 +3,7 @@
 #include "Python.h"
 #include "pycore_call.h"          // _PyObject_CallNoArgs()
 #include "pycore_runtime.h"       // _PyRuntime
+#include "pycore_critical_section.h"

 #ifdef HAVE_UNISTD_H
 #  include <unistd.h>             // isatty()
@@ -101,34 +102,33 @@ PyFile_GetLine(PyObject *f, int n)

 /* Interfaces to write objects/strings to file-like objects */

+static inline int
+_PyFile_WriteObject(PyObject *f, PyObject *v)
+{
+    PyObject *writer = PyObject_GetAttr(f, &_Py_ID(write));
+    if (writer == NULL) return -1;
+    PyObject *res = PyObject_CallOneArg(writer, v);
+    Py_DECREF(writer);
+    if (res == NULL) return -1;
+    Py_DECREF(res);
+    return 0;
+}
+
 int
 PyFile_WriteObject(PyObject *v, PyObject *f, int flags)
 {
-    PyObject *writer, *value, *result;

     if (f == NULL) {
         PyErr_SetString(PyExc_TypeError, "writeobject with NULL file");
         return -1;
     }
-    writer = PyObject_GetAttr(f, &_Py_ID(write));
-    if (writer == NULL)
-        return -1;
-    if (flags & Py_PRINT_RAW) {
-        value = PyObject_Str(v);
-    }
-    else
-        value = PyObject_Repr(v);
-    if (value == NULL) {
-        Py_DECREF(writer);
-        return -1;
-    }
-    result = PyObject_CallOneArg(writer, value);
+    int rc = 0;
+    PyObject *value = (flags & Py_PRINT_RAW) ? PyObject_Str(v) : PyObject_Repr(v);
+    Py_BEGIN_CRITICAL_SECTION(f);
+    rc = _PyFile_WriteObject(f, value);
+    Py_END_CRITICAL_SECTION();
     Py_DECREF(value);
-    Py_DECREF(writer);
-    if (result == NULL)
-        return -1;
-    Py_DECREF(result);
-    return 0;
+    return rc;
 }

@picnixz
Copy link
Member

picnixz commented Feb 16, 2025

And adding a critical section to print also doesn't help =/

@picnixz
Copy link
Member

picnixz commented Feb 16, 2025

A funny observation. When using print(file=...) directly without changing sys.stdout, I can't get a segfault as frequently (I didn't hit one yet). So it could really be sys.stdout itself. I didn't manage to get a segfault if I directly call text.write() =/

@devdanzin
Copy link
Contributor Author

Not sure this helps, but I get a (non-deterministic) segfault under GDB with:

from contextlib import redirect_stdout
from threading import Thread
import sys
import time

def test_redirect():
    text = open("/dev/null", "w")
    with redirect_stdout(text):
        sys.stdout.buffer.write(b"hello1")
        time.sleep(0.3)
        sys.stdout.buffer.write(b"hello1")

for x in range(200):
    Thread(target=test_redirect, args=()).start()

The backtrace is:

#0  PyObject_CallFinalizerFromDealloc (self=0x200381b0110) at Objects/object.c:602
#1  0x000055555598aa30 in _PyIOBase_finalize (self=self@entry=0x200381b0110) at ./Modules/_io/iobase.c:340
#2  0x000055555599da85 in textiowrapper_dealloc (op=0x200381b0110) at ./Modules/_io/textio.c:1468
#3  0x000055555570d483 in _Py_Dealloc (op=op@entry=0x200381b0110) at Objects/object.c:3015
#4  0x000055555570d642 in _Py_DecRefSharedDebug (o=o@entry=0x200381b0110,
    filename=filename@entry=0x5555559f662f "./Include/refcount.h", lineno=lineno@entry=502)
    at Objects/object.c:418
#5  0x00005555556e55b4 in Py_DECREF (filename=0x5555559f662f "./Include/refcount.h", lineno=502,
    op=0x200381b0110) at ./Include/refcount.h:347
#6  0x00005555556f38b7 in Py_XDECREF (op=<optimized out>) at ./Include/refcount.h:502
#7  insertdict (interp=<optimized out>, mp=mp@entry=0x2000001f850,
    key=key@entry=0x555555c801d8 <_PyRuntime+106200>, hash=737787358347787621,
    value=value@entry=0x2003a1b0110) at Objects/dictobject.c:1864
#8  0x00005555556f3b09 in setitem_take2_lock_held (mp=mp@entry=0x2000001f850,
    key=key@entry=0x555555c801d8 <_PyRuntime+106200>, value=value@entry=0x2003a1b0110)
    at Objects/dictobject.c:2594
#9  0x00005555556f3c5a in setitem_lock_held (mp=mp@entry=0x2000001f850,
    key=key@entry=0x555555c801d8 <_PyRuntime+106200>, value=value@entry=0x2003a1b0110)
    at ./Include/refcount.h:519
#10 0x00005555556f456e in _PyDict_SetItem_LockHeld (dict=dict@entry=0x2000001f850,
    name=name@entry=0x555555c801d8 <_PyRuntime+106200>, value=value@entry=0x2003a1b0110)
    at Objects/dictobject.c:6829
#11 0x00005555556f467d in _PyObjectDict_SetItem (tp=tp@entry=0x555555c3e3a0 <PyModule_Type>,
    obj=obj@entry=0x20000259f50, dictptr=0x20000259f70, key=key@entry=0x555555c801d8 <_PyRuntime+106200>,
    value=value@entry=0x2003a1b0110) at Objects/dictobject.c:7502
#12 0x000055555571118e in _PyObject_GenericSetAttrWithDict (obj=0x20000259f50,
    name=0x555555c801d8 <_PyRuntime+106200>, value=<optimized out>, dict=dict@entry=0x0)
    at Objects/object.c:1853
#13 0x00005555557113c4 in PyObject_GenericSetAttr (obj=<optimized out>, name=<optimized out>,
    value=<optimized out>) at Objects/object.c:1881
#14 0x000055555570fbe8 in PyObject_SetAttr (v=0x20000259f50, name=<optimized out>, value=0x2003a1b0110)
    at Objects/object.c:1443
#15 0x000055555582d976 in builtin_setattr_impl (module=module@entry=0x2000025c5d0, obj=<optimized out>,
    name=<optimized out>, value=<optimized out>) at Python/bltinmodule.c:1695
#16 0x000055555582d9d1 in builtin_setattr (module=0x2000025c5d0, args=args@entry=0x7fffb67fbb48,
    nargs=nargs@entry=3) at Python/clinic/bltinmodule.c.h:660
#17 0x000055555584b9ed in _PyEval_EvalFrameDefault (tstate=tstate@entry=0x555555d90f10,
    frame=0x7ffff742b240, frame@entry=0x7ffff742b020, throwflag=throwflag@entry=0)
    at Python/generated_cases.c.h:2011

@picnixz
Copy link
Member

picnixz commented Feb 16, 2025

Not sure this helps, but I get a (non-deterministic) segfault under GDB with:

Yes, but this assumes that sys.stdout is replaced by whatever object you're using. Note that sys.stdout is stored at the interpreter level not just at the module level I think. So I think it's really the fact that we substitute sys.stdout for something that is not the original one.

Btw, I didn't manage to have a segfault with your latest reproducer so maybe it's also an OS/kernel issue?

@devdanzin
Copy link
Contributor Author

Here's one that sometimes segfaults for me under GDB without sys.stdout:

from threading import Thread
import time

null = open("/dev/null", "w")

class Dummy:
    stdout = null

dummy = Dummy()

def test_redirect():
    old_stdout = dummy.stdout
    dummy.stdout = open("/dev/null", "w")
    dummy.stdout.buffer.write(b"hello1\n")
    time.sleep(0.3)
    dummy.stdout.buffer.write(b"hello2\n")
    dummy.stdout = old_stdout
    dummy.stdout.buffer.write(b"hello3\n")

for x in range(200):
    Thread(target=test_redirect, args=()).start()

Backtrace same as the one before.

@picnixz
Copy link
Member

picnixz commented Feb 16, 2025

I don't know why I can make it fail on my side :') I only get ValueError: write to closed file. However, this could help us targetting the issue. Do you think it'll also be possible to use a normal file to write to instead of /dev/null?

@picnixz
Copy link
Member

picnixz commented Feb 16, 2025

Ok, so let's track it down separately. We can use this issue for the non thread-safetiness of print (and remove the free-threading label as it also affects GIL-enabled builds) and create another one for the ressurection. WDYT? I unfortunately have no knowledge in this area so if you have time, could you open the issue with what needs / can be done, please? TiA.

@colesbury
Copy link
Contributor

I've updated the description in this issue and filed #130202 for the resurrection. If someone wants to take on the _PySys_GetAttr() problem (this issue), that'd be great.

@picnixz picnixz changed the title Segfault in a freethreaded build from using contextlib.redirect_stdout in threads Crash when concurrently writing with print and concurrently modifying sys.stdout Feb 16, 2025
@sergey-miryanov
Copy link
Contributor

If @devdanzin wouldn't, I will try.

@ZeroIntensity
Copy link
Member

There's an open C API WG discussion about the problem with _PySys_GetAttr and friends. I think we'll need a new internal function, so you can take inspiration from some of the designs there.

@devdanzin
Copy link
Contributor Author

If @devdanzin wouldn't, I will try.

Oh, I wouldn't know how. Feel free to take it forward.

@sergey-miryanov
Copy link
Contributor

sergey-miryanov commented Feb 17, 2025

Oh, I wouldn't know how. Feel free to take it forward.

Thanks, I will try.

@sergey-miryanov
Copy link
Contributor

sergey-miryanov commented Feb 23, 2025

I've looked at how _PySys_GetAttr is used. I can reproduce the segfault error in some places where it's used. I've written tests for these places.

@colesbury @ZeroIntensity, @serhiy-storchaka please take a look.

Here's a copy from my PR:

Repro Tests Raised exception
_pickle.c/whichmodule No No Don't keep
_threadmodule.c/thread_excepthook No No Keep
faulthandler.c/faulthandler_get_fileno Yes Yes Don't keep
bltinmodule.c/builtin_print_impl Yes Yes Don't keep
bltinmodule.c/builtin_input_impl Yes Yes Don't keep
errors.c/write_unraisable_exc No No Keep
errors.c/format_unraisable_v Yes Yes Keep
_warnings.c/show_warning Yes Yes Don't keep
intrinsics.c/print_expr No No Don't keep
pylifecycle.c/flush_std_files Yes/No Yes/No Don't keep
pythonrun.c/_PyRun_InteractiveLoopObject No No Don't keep
pythonrun.c/pyrun_one_parse_ast No No Don't keep
pythonrun.c/_Py_HandleSystemExitAndKeyboardInterrupt No No Don't keep
pythonrun.c/_PyErr_PrintEx Yes Yes Don't keep
pythonrun.c/PyErr_Display No No Don't keep
pythonrun.c/flush_io_stream No No Don't keep
sysmodule.c/sys_displayhook Maybe No Don't keep
sysmodule.c/get_warnoptions No No Don't keep
sysmodule.c/PySys_ResetWarnOptions No No Don't keep
sysmodule.c/PySys_HasWarnOptions No No Don't keep
sysmodule.c/_PySys_AddXOptionWithError No No Don't keep
sysmodule.c/PySys_SetArgvEx No No Don't keep
sysmodule.c/sys_write No No Don't keep
sysmodule.c/sys_format No No Don't keep
traceback.c/_Py_FindSourceFile No No Don't keep
  • I can get a "segfault" error when I use sys_displayhook, but not where it's used.
  • For sys_write, sys_format - I have checked all the places where they called, and most of the locations are safe. However, a few places use %s specifier, in such places it is very tricky to get segfault.
  • get_warnoptions, PySys_ResetWarnOptions, _PySys_AddXOptionWithError - are deprecated, but it is a very tricky to get segfault too.
  • flush_io_stream, PyErr_Display, pyrun_one_parse_ast, print_expr, write_unraisable_exc, thread_excepthook - very tight - They use a borrowed reference right after getting. It might be possible to reproduce it under heavy contention, but I wasn't able to do so.
  • _PyRun_InteractiveLoopObject only checks presence of ps1 and ps2.
  • flush_std_files used from _Py_Finalize and from fatal_error. For _Py_Finalize I can repro, for fatal_error - no.
  • whichmodule, _Py_FindSourceFile iterate borrowed reference, but I wasn't able to reproduce segfault.
  • Keep or not before raised exception - in the most places _PySys_GetAttr called without an exception set.

Also, can you point me out what to do next? I can replace _PySys_GetAttr with _PySys_GetAttrRef, but in the most places it is interleave with @serhiy-storchaka PRs. I'm not sure what the correct way to deal with this situation is.

@serhiy-storchaka
Copy link
Member

#130503 is an adaptation of #111035 or #129736 that does not introduce new public API and does not change the current behavior (except fixing crashes, mainly). It will make minimal difference with #111035 or #129736, whatever will be accepted for future Python version.

I added also tests for print(), input() and sys.displayhook() (they are relatively simple). Reproducers for other crashes are harder, so I do not think that this is worth hassle.

Thank you for your tests, @sergey-miryanov, but sorry, I have not used them. They are high quality, but too large and expensive. It is not worth to keep them forever after fixing this issue.

@sergey-miryanov
Copy link
Contributor

@serhiy-storchaka I simplified it a bit yesterday, not sure if you saw the latest changes. Maybe it will be useful, but it is all up to you. Anyway, it was very interesting.

serhiy-storchaka added a commit that referenced this issue Feb 25, 2025
The use of PySys_GetObject() and _PySys_GetAttr(), which return a borrowed
reference, has been replaced by using one of the following functions, which
return a strong reference and distinguish a missing attribute from an error:
_PySys_GetOptionalAttr(), _PySys_GetOptionalAttrString(),
_PySys_GetRequiredAttr(), and _PySys_GetRequiredAttrString().
serhiy-storchaka added a commit to serhiy-storchaka/cpython that referenced this issue Feb 25, 2025
…honGH-130503)

The use of PySys_GetObject() and _PySys_GetAttr(), which return a borrowed
reference, has been replaced by using one of the following functions, which
return a strong reference and distinguish a missing attribute from an error:
_PySys_GetOptionalAttr(), _PySys_GetOptionalAttrString(),
_PySys_GetRequiredAttr(), and _PySys_GetRequiredAttrString().
(cherry picked from commit 0ef4ffe)

Co-authored-by: Serhiy Storchaka <[email protected]>
serhiy-storchaka added a commit that referenced this issue Feb 25, 2025
GH-130556)

The use of PySys_GetObject() and _PySys_GetAttr(), which return a borrowed
reference, has been replaced by using one of the following functions, which
return a strong reference and distinguish a missing attribute from an error:
_PySys_GetOptionalAttr(), _PySys_GetOptionalAttrString(),
_PySys_GetRequiredAttr(), and _PySys_GetRequiredAttrString().
(cherry picked from commit 0ef4ffe)
serhiy-storchaka added a commit to serhiy-storchaka/cpython that referenced this issue Feb 26, 2025
serhiy-storchaka added a commit to serhiy-storchaka/cpython that referenced this issue Feb 26, 2025
…honGH-130503) (pythonGH-130556)

The use of PySys_GetObject() and _PySys_GetAttr(), which return a borrowed
reference, has been replaced by using one of the following functions, which
return a strong reference and distinguish a missing attribute from an error:
_PySys_GetOptionalAttr(), _PySys_GetOptionalAttrString(),
_PySys_GetRequiredAttr(), and _PySys_GetRequiredAttrString().
(cherry picked from commit 0ef4ffe)
(cherry picked from commit 7c1b76f)

Co-authored-by: Serhiy Storchaka <[email protected]>
serhiy-storchaka added a commit to serhiy-storchaka/cpython that referenced this issue Feb 26, 2025
serhiy-storchaka added a commit that referenced this issue Feb 26, 2025
GH-130556) (GH-130576)

The use of PySys_GetObject() and _PySys_GetAttr(), which return a borrowed
reference, has been replaced by using one of the following functions, which
return a strong reference and distinguish a missing attribute from an error:
_PySys_GetOptionalAttr(), _PySys_GetOptionalAttrString(),
_PySys_GetRequiredAttr(), and _PySys_GetRequiredAttrString().

(cherry picked from commit 0ef4ffe)
(cherry picked from commit 7c1b76f)
(cherry picked from commit 2ab7e11)
@vstinner
Copy link
Member

I cannot reproduce the crash using #130163 (comment) reproducer. Can we close the issue?

@serhiy-storchaka
Copy link
Member

It has already been fixed.

seehwan pushed a commit to seehwan/cpython that referenced this issue Apr 16, 2025
…30503)

The use of PySys_GetObject() and _PySys_GetAttr(), which return a borrowed
reference, has been replaced by using one of the following functions, which
return a strong reference and distinguish a missing attribute from an error:
_PySys_GetOptionalAttr(), _PySys_GetOptionalAttrString(),
_PySys_GetRequiredAttr(), and _PySys_GetRequiredAttrString().
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
interpreter-core (Objects, Python, Grammar, and Parser dirs) topic-C-API type-crash A hard crash of the interpreter, possibly with a core dump
Projects
None yet
Development

No branches or pull requests

8 participants