classification
Title: Python 3.6b2 crashes with "Python memory allocator called without holding the GIL"
Type: crash Stage: resolved
Components: Library (Lib) Versions: Python 3.7, Python 3.6
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: Nosy List: christian.heimes, methane, ned.deily, python-dev, serhiy.storchaka, vstinner, yselivanov
Priority: Keywords: patch

Created on 2016-10-18 19:18 by yselivanov, last changed 2016-10-20 23:08 by python-dev. This issue is now closed.

Files
File name Uploaded Description Edit
issue28471.patch yselivanov, 2016-10-18 19:46 review
Messages (16)
msg278921 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2016-10-18 19:18
The following Python program causes a segfault in Python 3.6b2:

    import socket
    import asyncio

    loop = asyncio.get_event_loop()


    sock = socket.socket()
    sock.close()

    async def client():
        reader, writer = await asyncio.open_connection(
            sock=sock,
            loop=loop)

    async def runner():
        await client()

    loop.run_until_complete(runner())
msg278923 - (view) Author: Ned Deily (ned.deily) * (Python committer) Date: 2016-10-18 19:26
Fatal Python error: Python memory allocator called without holding the GIL

Current thread 0x00007fffb043b3c0 (most recent call first):
  File "/py/dev/36/root/fwd_macports/Library/Frameworks/pytest_10.12.framework/Versions/3.6/lib/python3.6/asyncio/base_events.py", line 790 in _create_connection_transport
  File "/py/dev/36/root/fwd_macports/Library/Frameworks/pytest_10.12.framework/Versions/3.6/lib/python3.6/asyncio/base_events.py", line 777 in create_connection
  File "/py/dev/36/root/fwd_macports/Library/Frameworks/pytest_10.12.framework/Versions/3.6/lib/python3.6/asyncio/streams.py", line 75 in open_connection
  File "/Users/nad/Desktop/test_28471.py", line 13 in client
  File "/Users/nad/Desktop/test_28471.py", line 16 in runner
  File "/py/dev/36/root/fwd_macports/Library/Frameworks/pytest_10.12.framework/Versions/3.6/lib/python3.6/asyncio/tasks.py", line 239 in _step
  File "/py/dev/36/root/fwd_macports/Library/Frameworks/pytest_10.12.framework/Versions/3.6/lib/python3.6/asyncio/events.py", line 126 in _run
  File "/py/dev/36/root/fwd_macports/Library/Frameworks/pytest_10.12.framework/Versions/3.6/lib/python3.6/asyncio/base_events.py", line 1390 in _run_once
  File "/py/dev/36/root/fwd_macports/Library/Frameworks/pytest_10.12.framework/Versions/3.6/lib/python3.6/asyncio/base_events.py", line 405 in run_forever
  File "/py/dev/36/root/fwd_macports/Library/Frameworks/pytest_10.12.framework/Versions/3.6/lib/python3.6/asyncio/base_events.py", line 437 in run_until_complete
  File "/Users/nad/Desktop/test_28471.py", line 18 in <module>
Abort trap: 6
msg278925 - (view) Author: Ned Deily (ned.deily) * (Python committer) Date: 2016-10-18 19:37
And here's an OS X debug-build stack trace using the system malloc (current 3.6 tip, a218260334c4):

Thread 0 Crashed:: Dispatch queue: com.apple.main-thread
0   pytest_10.12                  	0x000000010256b794 PyObject_Call + 404 (abstract.c:2245)
1   pytest_10.12                  	0x00000001027797cf PyErr_SetFromErrnoWithFilenameObjects + 479 (errors.c:515)
2   pytest_10.12                  	0x00000001027799ff PyErr_SetFromErrno + 31 (errors.c:553)
3   _socket.cpython-36dm-darwin.so	0x0000000102c3a496 internal_setblocking + 118 (socketmodule.c:671)
4   _socket.cpython-36dm-darwin.so	0x0000000102c36473 sock_setblocking + 115 (socketmodule.c:2445)
5   pytest_10.12                  	0x000000010260be60 _PyCFunction_FastCallDict + 1104 (methodobject.c:209)
6   pytest_10.12                  	0x000000010260c305 _PyCFunction_FastCallKeywords + 501 (methodobject.c:295)
7   pytest_10.12                  	0x000000010274f76d call_function + 637 (ceval.c:4784)
8   pytest_10.12                  	0x00000001027487de _PyEval_EvalFrameDefault + 78878 (ceval.c:3271)
9   pytest_10.12                  	0x00000001027353b0 PyEval_EvalFrameEx + 80 (ceval.c:718)
10  pytest_10.12                  	0x00000001025b68bb gen_send_ex + 843 (genobject.c:216)
11  pytest_10.12                  	0x00000001025b6563 _PyGen_Send + 35 (genobject.c:343)
12  pytest_10.12                  	0x000000010273d915 _PyEval_EvalFrameDefault + 34133 (ceval.c:2021)
13  pytest_10.12                  	0x00000001027353b0 PyEval_EvalFrameEx + 80 (ceval.c:718)
14  pytest_10.12                  	0x00000001025b68bb gen_send_ex + 843 (genobject.c:216)
15  pytest_10.12                  	0x00000001025b6563 _PyGen_Send + 35 (genobject.c:343)
16  pytest_10.12                  	0x000000010273d915 _PyEval_EvalFrameDefault + 34133 (ceval.c:2021)
17  pytest_10.12                  	0x00000001027353b0 PyEval_EvalFrameEx + 80 (ceval.c:718)
18  pytest_10.12                  	0x00000001025b68bb gen_send_ex + 843 (genobject.c:216)
19  pytest_10.12                  	0x00000001025b6563 _PyGen_Send + 35 (genobject.c:343)
20  pytest_10.12                  	0x000000010273d915 _PyEval_EvalFrameDefault + 34133 (ceval.c:2021)
21  pytest_10.12                  	0x00000001027353b0 PyEval_EvalFrameEx + 80 (ceval.c:718)
22  pytest_10.12                  	0x00000001025b68bb gen_send_ex + 843 (genobject.c:216)
23  pytest_10.12                  	0x00000001025b6563 _PyGen_Send + 35 (genobject.c:343)
24  pytest_10.12                  	0x000000010273d915 _PyEval_EvalFrameDefault + 34133 (ceval.c:2021)
25  pytest_10.12                  	0x00000001027353b0 PyEval_EvalFrameEx + 80 (ceval.c:718)
26  pytest_10.12                  	0x00000001025b68bb gen_send_ex + 843 (genobject.c:216)
27  pytest_10.12                  	0x00000001025b6563 _PyGen_Send + 35 (genobject.c:343)
28  pytest_10.12                  	0x000000010260be60 _PyCFunction_FastCallDict + 1104 (methodobject.c:209)
29  pytest_10.12                  	0x000000010260c305 _PyCFunction_FastCallKeywords + 501 (methodobject.c:295)
30  pytest_10.12                  	0x000000010274f76d call_function + 637 (ceval.c:4784)
31  pytest_10.12                  	0x00000001027487de _PyEval_EvalFrameDefault + 78878 (ceval.c:3271)
32  pytest_10.12                  	0x00000001027353b0 PyEval_EvalFrameEx + 80 (ceval.c:718)
33  pytest_10.12                  	0x00000001027515f0 _PyEval_EvalCodeWithName + 5472 (ceval.c:4115)
34  pytest_10.12                  	0x0000000102752ca0 _PyFunction_FastCallDict + 1296 (ceval.c:5017)
35  pytest_10.12                  	0x000000010256bb82 _PyObject_FastCallDict + 562 (abstract.c:2297)
36  pytest_10.12                  	0x000000010256bf02 _PyObject_Call_Prepend + 370 (abstract.c:2360)
37  pytest_10.12                  	0x000000010259be9a method_call + 106 (classobject.c:317)
38  pytest_10.12                  	0x000000010256b7dd PyObject_Call + 477 (abstract.c:2248)
39  pytest_10.12                  	0x000000010274fd0c do_call_core + 508 (ceval.c:5053)
40  pytest_10.12                  	0x00000001027492ac _PyEval_EvalFrameDefault + 81644 (ceval.c:3353)
41  pytest_10.12                  	0x00000001027353b0 PyEval_EvalFrameEx + 80 (ceval.c:718)
42  pytest_10.12                  	0x0000000102752ee2 _PyFunction_FastCall + 370 (ceval.c:4866)
43  pytest_10.12                  	0x000000010275253e fast_function + 574 (ceval.c:4901)
44  pytest_10.12                  	0x000000010274f8f6 call_function + 1030 (ceval.c:4805)
45  pytest_10.12                  	0x00000001027487de _PyEval_EvalFrameDefault + 78878 (ceval.c:3271)
46  pytest_10.12                  	0x00000001027353b0 PyEval_EvalFrameEx + 80 (ceval.c:718)
47  pytest_10.12                  	0x0000000102752ee2 _PyFunction_FastCall + 370 (ceval.c:4866)
48  pytest_10.12                  	0x000000010275253e fast_function + 574 (ceval.c:4901)
49  pytest_10.12                  	0x000000010274f8f6 call_function + 1030 (ceval.c:4805)
50  pytest_10.12                  	0x00000001027487de _PyEval_EvalFrameDefault + 78878 (ceval.c:3271)
51  pytest_10.12                  	0x00000001027353b0 PyEval_EvalFrameEx + 80 (ceval.c:718)
52  pytest_10.12                  	0x0000000102752ee2 _PyFunction_FastCall + 370 (ceval.c:4866)
53  pytest_10.12                  	0x000000010275253e fast_function + 574 (ceval.c:4901)
54  pytest_10.12                  	0x000000010274f8f6 call_function + 1030 (ceval.c:4805)
55  pytest_10.12                  	0x00000001027487de _PyEval_EvalFrameDefault + 78878 (ceval.c:3271)
56  pytest_10.12                  	0x00000001027353b0 PyEval_EvalFrameEx + 80 (ceval.c:718)
57  pytest_10.12                  	0x0000000102752ee2 _PyFunction_FastCall + 370 (ceval.c:4866)
58  pytest_10.12                  	0x000000010275253e fast_function + 574 (ceval.c:4901)
59  pytest_10.12                  	0x000000010274f8f6 call_function + 1030 (ceval.c:4805)
60  pytest_10.12                  	0x00000001027487de _PyEval_EvalFrameDefault + 78878 (ceval.c:3271)
61  pytest_10.12                  	0x00000001027353b0 PyEval_EvalFrameEx + 80 (ceval.c:718)
62  pytest_10.12                  	0x00000001027515f0 _PyEval_EvalCodeWithName + 5472 (ceval.c:4115)
63  pytest_10.12                  	0x000000010273532e PyEval_EvalCodeEx + 222 (ceval.c:4136)
64  pytest_10.12                  	0x000000010273523e PyEval_EvalCode + 94 (ceval.c:695)
65  pytest_10.12                  	0x00000001027a50cc run_mod + 108 (pythonrun.c:980)
66  pytest_10.12                  	0x00000001027a5b08 PyRun_FileExFlags + 264 (pythonrun.c:933)
67  pytest_10.12                  	0x00000001027a45d1 PyRun_SimpleFileExFlags + 1073 (pythonrun.c:396)
68  pytest_10.12                  	0x00000001027a3edc PyRun_AnyFileExFlags + 140 (pythonrun.c:80)
69  pytest_10.12                  	0x00000001027d5c4c run_file + 332 (main.c:319)
70  pytest_10.12                  	0x00000001027d49a9 Py_Main + 4473 (main.c:779)
71  pytest_10.12                  	0x000000010254fe5b 0x10254f000 + 3675
72  libdyld.dylib                 	0x00007fffa771b255 start + 1
msg278926 - (view) Author: Christian Heimes (christian.heimes) * (Python committer) Date: 2016-10-18 19:39
internal_setblocking() sets an exception w/o holding the GIL.

#0  0x00007ffff711f6f5 in __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:54
#1  0x00007ffff71212fa in __GI_abort () at abort.c:89
#2  0x000000000042935f in Py_FatalError (msg=0x83d8f8 "Python memory allocator called without holding the GIL")
    at Python/pylifecycle.c:1457
#3  0x000000000042138f in _PyMem_DebugCheckGIL () at Objects/obmalloc.c:1972
#4  0x00000000004214ae in _PyMem_DebugFree (ctx=0xad8bf0 <_PyMem_Debug+48>, ptr=0xcf8b40) at Objects/obmalloc.c:1994
#5  0x000000000041e9cb in PyMem_Free (ptr=0xcf8b40) at Objects/obmalloc.c:442
#6  0x000000000046f7ed in _PyFaulthandler_Fini () at ./Modules/faulthandler.c:1369
#7  0x0000000000429303 in Py_FatalError (msg=0x83d8f8 "Python memory allocator called without holding the GIL")
    at Python/pylifecycle.c:1431
#8  0x000000000042138f in _PyMem_DebugCheckGIL () at Objects/obmalloc.c:1972
#9  0x00000000004213d0 in _PyMem_DebugMalloc (ctx=0xad8c20 <_PyMem_Debug+96>, nbytes=84) at Objects/obmalloc.c:1980
#10 0x000000000041eb6b in PyObject_Malloc (size=84) at Objects/obmalloc.c:479
#11 0x00000000005c0a19 in PyUnicode_New (size=19, maxchar=116) at Objects/unicodeobject.c:1280
#12 0x00000000005c8e0e in PyUnicode_FromUnicode (u=0xd26450 L"Bad file descriptor", size=19) at Objects/unicodeobject.c:2016
#13 0x00000000005ce90f in PyUnicode_FromWideChar (w=0xd26450 L"Bad file descriptor", size=19) at Objects/unicodeobject.c:2497
#14 0x00000000005d48f0 in PyUnicode_DecodeLocaleAndSize (str=0x7ffff7273e98 "Bad file descriptor", len=19, 
    errors=0x8747bb "surrogateescape") at Objects/unicodeobject.c:3729
#15 0x00000000005d4f86 in PyUnicode_DecodeLocale (str=0x7ffff7273e98 "Bad file descriptor", errors=0x8747bb "surrogateescape")
    at Objects/unicodeobject.c:3802
#16 0x0000000000717924 in PyErr_SetFromErrnoWithFilenameObjects (exc=<type at remote 0xafee40>, filenameObject=0x0, filenameObject2=0x0)
    at Python/errors.c:448
#17 0x0000000000717f00 in PyErr_SetFromErrno (exc=<type at remote 0xafee40>) at Python/errors.c:553
#18 0x00007ffff03000b0 in internal_setblocking (s=0x7fffeb3e1d48, block=1) at /home/heimes/dev/python/cpython/Modules/socketmodule.c:667
#19 0x00007ffff030597a in sock_setblocking (s=0x7fffeb3e1d48, arg=False) at /home/heimes/dev/python/cpython/Modules/socketmodule.c:2445
#20 0x000000000054a2ce in _PyCFunction_FastCallDict (func_obj=<built-in method setblocking of socket object at remote 0x7fffeb3e1d48>, 
    args=0xef4058, nargs=1, kwargs=0x0) at Objects/methodobject.c:209
#21 0x000000000054a963 in _PyCFunction_FastCallKeywords (func=<built-in method setblocking of socket object at remote 0x7fffeb3e1d48>, 
    stack=0xef4058, nargs=1, kwnames=0x0) at Objects/methodobject.c:295
#22 0x00000000006e306c in call_function (pp_stack=0x7ffffffe9088, oparg=1, kwnames=0x0) at Python/ceval.c:4787
msg278927 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2016-10-18 19:39
I have a patch already, writing a unittest.
msg278928 - (view) Author: Christian Heimes (christian.heimes) * (Python committer) Date: 2016-10-18 19:42
It's my fault. I added the "goto error" w/o realizing that I forgot to re-acquire the GIL.
msg278929 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2016-10-18 19:46
Attaching a patch to fix this. Please review.
msg278930 - (view) Author: Christian Heimes (christian.heimes) * (Python committer) Date: 2016-10-18 19:57
LGTM, thanks Yury!
msg278931 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2016-10-18 19:58
> LGTM, thanks Yury!

NP :)  Should this be committed to 3.6/default, or in 3.5 too?
msg278933 - (view) Author: Christian Heimes (christian.heimes) * (Python committer) Date: 2016-10-18 20:00
3.5 is not affected by the crasher. I only added the error check to default (3.6).
msg278934 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2016-10-18 20:03
> Fatal Python error: Python memory allocator called without holding the GIL

Oh, I didn't expect that my new check would catch such bug. Nice.

In release mode, the check is disabled by default (can be enabled at
runtime), and I don't think that the code can crash.

But the bug should be fixed anyway :-)
msg278935 - (view) Author: Roundup Robot (python-dev) (Python triager) Date: 2016-10-18 20:06
New changeset 4b5b233d4c98 by Yury Selivanov in branch '3.6':
Issue #28471: Fix crash (GIL state related) in socket.setblocking
https://hg.python.org/cpython/rev/4b5b233d4c98

New changeset 554fb699af8c by Yury Selivanov in branch 'default':
Merge 3.6 (issue #28471)
https://hg.python.org/cpython/rev/554fb699af8c
msg278936 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2016-10-18 20:06
> In release mode, the check is disabled by default (can be enabled at
runtime), and I don't think that the code can crash.

It actually crashed in release mode for me.  Maybe the exact location of SF was different, but whatever...

Anyways, closing the issue. Thanks for the review Christian!
msg278938 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2016-10-18 21:20
I'm curious. I tested in release mode, the example does crash:

$ ./python x.py 
Segmentation fault (core dumped)


I'm able to get a Python traceback using PYTHONMALLOC=debug:

$ PYTHONMALLOC=debug ./python x.py 
Fatal Python error: Python memory allocator called without holding the GIL

Current thread 0x00007f65bd74b700 (most recent call first):
  File "/home/haypo/prog/python/default/Lib/asyncio/base_events.py", line 790 in _create_connection_transport
  File "/home/haypo/prog/python/default/Lib/asyncio/base_events.py", line 777 in create_connection
  File "/home/haypo/prog/python/default/Lib/asyncio/streams.py", line 75 in open_connection
  File "x.py", line 13 in client
  File "x.py", line 16 in runner
  File "/home/haypo/prog/python/default/Lib/asyncio/tasks.py", line 239 in _step
  File "/home/haypo/prog/python/default/Lib/asyncio/events.py", line 126 in _run
  File "/home/haypo/prog/python/default/Lib/asyncio/base_events.py", line 1390 in _run_once
  File "/home/haypo/prog/python/default/Lib/asyncio/base_events.py", line 405 in run_forever
  File "/home/haypo/prog/python/default/Lib/asyncio/base_events.py", line 437 in run_until_complete
  File "x.py", line 18 in <module>
Aborted (core dumped)
msg278941 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2016-10-18 21:43
> I'm curious. I tested in release mode, the example does crash:

Well, since the GIL wasn't properly acquired, it's only a matter of time until something else crashes.
msg279090 - (view) Author: Roundup Robot (python-dev) (Python triager) Date: 2016-10-20 23:08
New changeset 2fd92794f775 by Martin Panter in branch '3.6':
Issue #28471: Avoid ResourceWarning by detaching test socket
https://hg.python.org/cpython/rev/2fd92794f775
History
Date User Action Args
2016-10-20 23:08:59python-devsetmessages: + msg279090
2016-10-18 21:43:56yselivanovsetmessages: + msg278941
2016-10-18 21:20:14vstinnersetmessages: + msg278938
2016-10-18 20:07:41ned.deilysetpriority: release blocker ->
2016-10-18 20:06:42yselivanovsetstatus: open -> closed
messages: + msg278936

components: + Library (Lib), - Interpreter Core
resolution: fixed
stage: patch review -> resolved
2016-10-18 20:06:04python-devsetnosy: + python-dev
messages: + msg278935
2016-10-18 20:03:23vstinnersetmessages: + msg278934
2016-10-18 20:00:26christian.heimessetmessages: + msg278933
2016-10-18 19:58:10yselivanovsetmessages: + msg278931
2016-10-18 19:57:05christian.heimessettype: crash
stage: patch review
messages: + msg278930
versions: + Python 3.7
2016-10-18 19:46:44yselivanovsetfiles: + issue28471.patch
keywords: + patch
messages: + msg278929
2016-10-18 19:42:52christian.heimessetmessages: + msg278928
2016-10-18 19:39:17yselivanovsetmessages: + msg278927
2016-10-18 19:39:12christian.heimessetnosy: + christian.heimes
messages: + msg278926
2016-10-18 19:38:00ned.deilysetmessages: + msg278925
2016-10-18 19:26:25ned.deilysetmessages: + msg278923
2016-10-18 19:18:37yselivanovcreate