Repository navigation
pyro4 with more than 15 threads often crashes 2.7.12 #72859
Description
| BPO | 28673 |
|---|---|
| Nosy | @irmen, @vstinner, @ericvsmith, @methane |
| Files |
Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.
Show more details
GitHub fields:
assignee = None
closed_at = <Date 2019-02-15.09:56:24.001>
created_at = <Date 2016-11-12.08:31:38.310>
labels = ['interpreter-core', 'type-crash']
title = 'pyro4 with more than 15 threads often crashes 2.7.12'
updated_at = <Date 2019-02-15.09:56:24.000>
user = 'https://bugs.python.org/pwp333'bugs.python.org fields:
activity = <Date 2019-02-15.09:56:24.000>
actor = 'methane'
assignee = 'none'
closed = True
closed_date = <Date 2019-02-15.09:56:24.001>
closer = 'methane'
components = ['Interpreter Core']
creation = <Date 2016-11-12.08:31:38.310>
creator = 'pwp333'
dependencies = []
files = ['45492', '45624', '45633', '45643', '45659']
hgrepos = []
issue_num = 28673
keywords = ['patch']
message_count = 19.0
messages = ['280640', '280664', '280750', '280896', '280897', '280909', '280911', '280921', '280922', '281067', '281579', '281630', '281665', '281676', '281680', '281718', '281721', '281811', '335594']
nosy_count = 5.0
nosy_names = ['irmen', 'vstinner', 'eric.smith', 'methane', 'pwp333']
pr_nums = []
priority = 'normal'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = 'crash'
url = 'https://bugs.python.org/issue28673'
versions = ['Python 2.7']
Activity
pwp333 commentedon Nov 12, 2016
When using pyro4 with more than 15 threads, python 2.7.12 cores frequently (>60% time)
Note "v" (op in frame 1) in frame 2 is NULL which has some value in frame 3. So some other thread cleans it.
=== gdb ===
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `python /etc/remoting/remoting_agent.zip run --system'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 PyDict_SetItem (op=op@entry=0x0, key=key@entry=0x7f0aa11cd420, value=value@entry=0x920ce0 <_PyExc_AttributeError.12478>) at ../Objects/dictobject.c:832
warning: Source file is more recent than executable.
832 if (!PyDict_Check(op)) {
(gdb) bt
#0 PyDict_SetItem (op=op@entry=0x0, key=key@entry='exc_type', value=value@entry=<type at remote 0x920ce0>) at ../Objects/dictobject.c:832
#1 0x0000000000529e86 in PyDict_SetItemString (item=<type at remote 0x920ce0>, key=0x61d02a "exc_type", v=0x0) at ../Objects/dictobject.c:2469
#2 PySys_SetObject (name=name@entry=0x61d02a "exc_type", v=v@entry=<type at remote 0x920ce0>) at ../Python/sysmodule.c:83
#3 0x000000000055acc0 in set_exc_info (tb=<traceback at remote 0x7f0aa1232878>, value=exceptions.AttributeError("'NoneType' object has no attribute 'SHUT_RDWR'",),
type=<type at remote 0x920ce0>, tstate=0x95ad10) at ../Python/ceval.c:3736
#4 PyEval_EvalFrameEx (f=f@entry=Frame 0x7f0a9e929b60, for file /etc/remoting/remoting_agent.zip/Pyro4/socketutil.py, line 463, in close (self=<SocketConnection at remote 0x7f0a9e924510>),
throwflag=throwflag@entry=0) at ../Python/ceval.c:3251
#5 0x0000000000559c27 in fast_function (nk=<optimized out>, na=<optimized out>, n=1, pp_stack=0x7ffce435ab00, func=<function at remote 0x7f0a9f6c0230>) at ../Python/ceval.c:4435
#6 call_function (oparg=<optimized out>, pp_stack=0x7ffce435ab00) at ../Python/ceval.c:4370
#7 PyEval_EvalFrameEx (f=f@entry=Frame 0x7f0a40000b50, for file /etc/remoting/remoting_agent.zip/Pyro4/socketutil.py, line 453, in __del__ (self=<SocketConnection at remote 0x7f0a9e924510>),
throwflag=throwflag@entry=0) at ../Python/ceval.c:2987
#8 0x000000000056aa8a in PyEval_EvalCodeEx (closure=<optimized out>, defcount=<optimized out>, defs=0x0, kwcount=<optimized out>, kws=<optimized out>, argcount=1073744720, args=<optimized out>,
locals=0x0, globals=<optimized out>, co=<optimized out>) at ../Python/ceval.c:3582
#9 function_call (func=func@entry=<function at remote 0x7f0a9f6c00c8>, arg=arg@entry=(<SocketConnection at remote 0x7f0a9e924510>,), kw=kw@entry=0x0) at ../Objects/funcobject.c:523
#10 0x00000000004be724 in PyObject_Call (kw=0x0, arg=(<SocketConnection at remote 0x7f0a9e924510>,), func=<function at remote 0x7f0a9f6c00c8>) at ../Objects/abstract.c:2546
#11 instancemethod_call.8803 (func=<function at remote 0x7f0a9f6c00c8>, arg=(<SocketConnection at remote 0x7f0a9e924510>,), kw=0x0) at ../Objects/classobject.c:2602
#12 0x00000000004c4683 in PyObject_Call (kw=0x0, arg=(), func=<instancemethod at remote 0x7f0a9f7b5b90>) at ../Objects/abstract.c:2546
#13 PyEval_CallObjectWithKeywords (kw=0x0, arg=(), func=<instancemethod at remote 0x7f0a9f7b5b90>) at ../Python/ceval.c:4219
#14 slot_tp_del.25647 (self=self@entry=<SocketConnection at remote 0x7f0a9e924510>) at ../Objects/typeobject.c:5844
#15 0x00000000004c5880 in subtype_dealloc.25650 (self=<SocketConnection at remote 0x7f0a9e924510>) at ../Objects/typeobject.c:1002
#16 0x00000000005336cf in dict_dealloc.18423 (mp=0x7f0a9e93c398) at ../Objects/dictobject.c:1040
#17 0x00000000004c56e7 in subtype_dealloc.25650 (
self=<ClientConnectionJob(daemon=<Daemon(_Daemon__mustshutdown=<_Event(_Verbose__verbose=False, _Event__flag=True, _Event__cond=<_Condition(_Verbose__verbose=False, _Condition__lock=<thread.lock at remote 0x7f0a9f759790>, acquire=<built-in method acquire of thread.lock object at remote 0x7f0a9f759790>, _Condition__waiters=[], release=<built-in method release of thread.lock object at remote 0x7f0a9f759790>) at remote 0x7f0a9e9241d0>) at remote 0x7f0a9e924190>, objectsById={'root': <RootService(_scheduler=<Scheduler(_lock=<thread.lock at remote 0x7f0aa1211d50>, _operations={'cookie_9de0e8d93ed84452a1ce8cc92268979e': <Operation(_exception=None, _result='obj_450f0972022e41b2b7c1f29f49bdca83', _action=<function at remote 0x7f0a9f7b89b0>, _lock=<_RLock(_Verbose__verbose=False, _RLock__owner=None, _RLock__block=<thread.lock at remote 0x7f0a9f759370>, _RLock__count=0) at remote 0x7f0a9e936190>, _started_at=<float at remote 0xab90f8>, cookie='cookie_9de0e8d93ed84452a1ce8cc92268979e', _complete=<_Condition(_Condition__lock=...(truncated)) at ../Objects/typeobject.c:1035
#18 0x0000000000534b93 in frame_dealloc.14921 (f=Frame 0x7f0a9f6d49d8, for file /etc/remoting/remoting_agent.zip/Pyro4/socketserver/threadpool.py, line 39, in run ())
at ../Objects/frameobject.c:458
#19 0x00000000004d86c6 in tb_dealloc.46270 (tb=0x7f0aa1278f38) at ../Python/traceback.c:28
#20 0x00000000004d87e1 in tb_dealloc.46270 (tb=0x7f0aa1278ea8) at ../Python/traceback.c:27
#21 0x00000000005336cf in dict_dealloc.18423 (mp=0x7f0aa1277280) at ../Objects/dictobject.c:1040
#22 0x00000000005a52db in PyInterpreterState_Clear (interp=0x95ac80) at ../Python/pystate.c:111
#23 0x0000000000423aea in Py_Finalize () at ../Python/pythonrun.c:500
#24 0x00000000004672c5 in Py_Main (argc=<optimized out>, argv=0x7ffce435b2d8) at ../Modules/main.c:665
#25 0x00007f0aa0aa7f45 in __libc_start_main (main=0x4672f4 <main>, argc=4, argv=0x7ffce435b2d8, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffce435b2c8)
at libc-start.c:287
#26 0x000000000057c581 in _start ()
====
Google shows similar trace has been reported back in 2009 for python 2.6
https://bugs.launchpad.net/ubuntu/+source/system-config-printer/+bug/478071
ericvsmith commentedon Nov 12, 2016
Can you provide a short sample that causes this error? Without a way to reproduce it, there's not a lot we can do.
methane commentedon Nov 14, 2016
Traceback tells:
While cleaning up interp->sysdict...
#19 0x00000000004d86c6 in tb_dealloc.46270 (tb=0x7f0aa1278f38) at ../Python/traceback.c:28
#20 0x00000000004d87e1 in tb_dealloc.46270 (tb=0x7f0aa1278ea8) at ../Python/traceback.c:27
Removing some traceback from sysdict. Maybe, sys.exc_traceback.
#17 0x00000000004c56e7 in subtype_dealloc.25650 (
self=<ClientConnectionJob(daemon=<Daemon(_Daemon__mustshutdown=<_Event(_Verbose__verbose=False, _Event__flag=True, _Event__cond=<_Condition(_Verbose__verbose=False, _Condition__lock=<thread.lock at remote 0x7f0a9f759790>, acquire=<built-in method acquire of thread.lock object at remote 0x7f0a9f759790>, _Condition__waiters=[], release=<built-in method release of thread.lock object at remote 0x7f0a9f759790>) at remote 0x7f0a9e9241d0>) at remote 0x7f0a9e924190>, objectsById={'root': <RootService(_scheduler=<Scheduler(_lock=<thread.lock at remote 0x7f0aa1211d50>, _operations={'cookie_9de0e8d93ed84452a1ce8cc92268979e': <Operation(_exception=None, _result='obj_450f0972022e41b2b7c1f29f49bdca83', _action=<function at remote 0x7f0a9f7b89b0>, _lock=<_RLock(_Verbose__verbose=False, _RLock__owner=None, _RLock__block=<thread.lock at remote 0x7f0a9f759370>, _RLock__count=0) at remote 0x7f0a9e936190>, _started_at=<float at remote 0xab90f8>, cookie='cookie_9de0e8d93ed84452a1ce8cc92268979e', _complete=<_Condition(_Condition__lock=...(truncated)) at ../Objects/typeobject.c:1035
#18 0x0000000000534b93 in frame_dealloc.14921 (f=Frame 0x7f0a9f6d49d8, for file /etc/remoting/remoting_agent.zip/Pyro4/socketserver/threadpool.py, line 39, in run ())
at ../Objects/frameobject.c:458
Removing frame object owned by the traceback.
...
Calling SocketConnection.__del__. It calls SocketConnection.close.
#3 0x000000000055acc0 in set_exc_info (tb=<traceback at remote 0x7f0aa1232878>, value=exceptions.AttributeError("'NoneType' object has no attribute 'SHUT_RDWR'",),
type=<type at remote 0x920ce0>, tstate=0x95ad10) at ../Python/ceval.c:3736
SocketConnection.close raise AttributeError.
#2 PySys_SetObject (name=name@entry=0x61d02a "exc_type", v=v@entry=<type at remote 0x920ce0>) at ../Python/sysmodule.c:83
Trying to register the exception to sys.
#0 PyDict_SetItem (op=op@entry=0x0, key=key@entry='exc_type', value=value@entry=<type at remote 0x920ce0>) at ../Objects/dictobject.c:832
But interp->sysdict is NULL already.
pwp333 commentedon Nov 15, 2016
Core is uploaded for python 2.7.10 to assist debugging.
vstinner commentedon Nov 15, 2016
Try to get the Python traceback of thread on the crash: try the faulthandler module.
pwp333 commentedon Nov 16, 2016
(gdb) py-bt
#4 Frame 0x7f0ab7a2db60, for file /etc/remoting/remoting_agent.zip/Pyro4/socketutil.py, line 463, in close (self=<SocketConnection at remote 0x7f0ab7a24190>)
self.sock.shutdown(socket.SHUT_RDWR)
#7 Frame 0x7f0ab0001760, for file /etc/remoting/remoting_agent.zip/Pyro4/socketutil.py, line 453, in __del__ (self=<SocketConnection at remote 0x7f0ab7a24190>)
self.close()
(gdb) py-list
458 def recv(self, size):
459 return receiveData(self.sock, size)
460
461 def close(self):
462 try:
methane commentedon Nov 16, 2016
Can you check backtrace of main thread?
vstinner commentedon Nov 16, 2016
Ok but can you also try faulthandler to see all frames of all threads?
vstinner commentedon Nov 16, 2016
By the way, you can try your application on Python 3.6 using
PYTHONMALLOC=debug env var.
Or retry your application on Python 2.7 recompiled using ./configure
--with-pydebug.
I would like to know if Python sees a buffer overflow.
pwp333 commentedon Nov 17, 2016
Could you please look into the core (attached into this bug) to figure out? This issue does not happen always. We are tight on resource to reproduce this.
[-]When using pyro4 with more than 15 threads, python 2.7.12 cores frequently[/-][+]pyro4 with more than 15 threads often crashes 2.7.12[/+]irmen commentedon Nov 23, 2016
Due to lack of example code to reproduce the issue, and because I'm mildly interested in this bug because it mentions Pyro4 (because I'm the author of that) I've tried to crash my system myself using Pyro4 and a simple torture test but it trucked on just fine.
Pyro4 is not doing any "strange" things as far as I am aware. It does have its own (simple) thread pool of regular Python threads that are handling incoming proxy connections.
(Had Pyro4 been doing weird things I suppose Python itself still should never core dump on the user but rather raise a regular exception if something was wrong)
methane commentedon Nov 24, 2016
I can't get same C traceback yet.
But attached script segfaults by different C traceback.
I think this issue is dup of bpo-1856
irmen commentedon Nov 24, 2016
The 28673-reproduce.py didn't crash on any of the systems I've tried it on. Are you sure it is complete? It looks like a part is missing.
methane commentedon Nov 25, 2016
I'm sorry, I had uploaded script with wrong parameter.
Additionally, this script fails by chance.
methane commentedon Nov 25, 2016
Python 3 would have bpo-21963 too. If we can fix it, we can fix this issue
too.
methane commentedon Nov 25, 2016
This script can cause deadlock on Python 3.6.
I suggest thread_PyThread_start_new_thread() raise RuntimeError("can't start thread: finalizing")
vstinner commentedon Nov 25, 2016
Where *exactly*? Py_FinalizeEx() first calls
wait_for_thread_shutdown() and *then* sets _Py_Finalizing to tstate.
Does wait_for_thread_shutdown() complete on this bug?
Note: It's not the first time that I noticed a deadlock around this
code :-/ I recall a silly bug when you press CTRL+c while
wait_for_thread_shutdown() is running.
See for example threading_shutdown_interrupted.py attached to the
issue bpo-20526. Run it and quickly press CTRL+c. Sometime, it does crash
Python with a segfault...
---
haypo@selma$ ./python threading_shutdown_interrupted.py ..........................................................................................................................................................................................................Exception ignored in: <module 'threading' from '/home/haypo/prog/python/default/Lib/threading.py'> Traceback (most recent call last): File "/home/haypo/prog/python/default/Lib/threading.py", line 1290, in _shutdown t.join() File "/home/haypo/prog/python/default/Lib/threading.py", line 1056, in join . self._wait_for_tstate_lock() File "/home/haypo/prog/python/default/Lib/threading.py", line 1072, in _wait_for_tstate_lock ... elif lock.acquire(block, timeout): File "threading_shutdown_interrupted.py", line 29, in killer .. raise KeyboardInterrupt() KeyboardInterrupt: ^CSegmentation fault (core dumped)Python finalization is a very fragile and complex task :-/
methane commentedon Nov 27, 2016
See attached patch.
But python with this patch can deadlock in other state. Main thread wait GIL
but no other living threads have GIL. It seems caused by other issue around finalization and multithreading.
Yes. wait_for_thread_shutdown() waits only daemon threads.
After _Py_Finalizing = tstate, main thread calls many __del__ methods
while shutdown. If one of them starts new thread, this deadlock happens.
methane commentedon Feb 15, 2019
I think this issue is fixed by bpo-21963.