[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[Roundup Robot]

Roundup Robot added the comment:

New changeset 9ce58a73b6b5 by Victor Stinner in branch '3.4':
Issue #20526, #19466: Revert changes of issue #19466 which introduces a
http://hg.python.org/cpython/rev/9ce58a73b6b5

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[Sebastien Renard]

Sebastien Renard added the comment:

Hello,

I encounter a quite similar issue with python 3.4.0 and cx_Oracle. It segfault 
from time to time (hard to reproduce) on visit_decref at Modules/gcmodule.c:373.
There were no issue with python 2.7. I did not test with 3.3.

With gdb i got the following stacktrace :
(gdb) info threads
  Id   Target Id Frame 
* 1Thread 0x77fc6740 (LWP 7415) "python3" visit_decref (op=0xb, 
data=data@entry=0x0) at Modules/gcmodule.c:373
(gdb) backtrace 
#0  visit_decref (op=0xb, data=data@entry=0x0) at Modules/gcmodule.c:373
#1  0x004318da in BaseException_traverse (self=0x71624888, 
visit=0x504660 , arg=0x0) at Objects/exceptions.c:97
#2  0x00504925 in subtract_refs (containers=) at 
Modules/gcmodule.c:398
#3  collect (generation=generation@entry=0, 
n_collected=n_collected@entry=0x7fffbd60, 
n_uncollectable=n_uncollectable@entry=0x7fffbd68, nofail=nofail@entry=0) at 
Modules/gcmodule.c:957
#4  0x00505573 in collect_with_callback (generation=0) at 
Modules/gcmodule.c:1128
#5  collect_generations () at Modules/gcmodule.c:1151
#6  0x00505cd1 in _PyObject_GC_Malloc (basicsize=) at 
Modules/gcmodule.c:1726
#7  _PyObject_GC_Malloc (basicsize=) at Modules/gcmodule.c:1743
#8  _PyObject_GC_NewVar (tp=tp@entry=0x810400 , 
nitems=nitems@entry=11) at Modules/gcmodule.c:1753
#9  0x0046470c in PyTuple_New (size=11) at Objects/tupleobject.c:104
#10 0x00464e05 in PyTuple_New (size=size@entry=11) at 
Objects/tupleobject.c:122
#11 0x7582e881 in Cursor_CreateRow (self=self@entry=0x71603290) at 
Cursor.c:1095
#12 0x7582f18f in Cursor_MultiFetch (self=0x71603290, rowLimit=0) 
at Cursor.c:1883
#13 0x004c4aa7 in call_function (oparg=, 
pp_stack=0x7fffbfb0) at Python/ceval.c:4210
#14 PyEval_EvalFrameEx (f=f@entry=0xab5208, throwflag=throwflag@entry=0) at 
Python/ceval.c:2829
#15 0x004be47b in PyEval_EvalCodeEx (_co=, 
globals=, locals=locals@entry=0x0, args=, 
argcount=argcount@entry=3, kws=0x711c3ad8, kwcount=0, defs=0x75a635a0, 
defcount=1, kwdefs=0x0, 
closure=0x0) at Python/ceval.c:3578
#16 0x004c3d91 in fast_function (nk=, na=3, n=, pp_stack=0x7fffc240, func=0x71e98b70) at Python/ceval.c:4334
#17 call_function (oparg=, pp_stack=0x7fffc240) at 
Python/ceval.c:4252
#18 PyEval_EvalFrameEx (f=f@entry=0x711c3930, throwflag=throwflag@entry=0) 
at Python/ceval.c:2829
#19 0x004be47b in PyEval_EvalCodeEx (_co=, 
globals=, locals=locals@entry=0x0, args=, 
argcount=argcount@entry=2, kws=0xbf7610, kwcount=1, defs=0x71eb14c0, 
defcount=1, kwdefs=0x0, 
closure=0x0) at Python/ceval.c:3578
#20 0x004c3d91 in fast_function (nk=, na=2, n=, pp_stack=0x7fffc4d0, func=0x7160b510) at Python/ceval.c:4334
#21 call_function (oparg=, pp_stack=0x7fffc4d0) at 
Python/ceval.c:4252
#22 PyEval_EvalFrameEx (f=, throwflag=throwflag@entry=0) at 
Python/ceval.c:2829
#23 0x004c5e85 in fast_function (nk=, na=2, n=2, 
pp_stack=0x7fffc6b0, func=0x71634d08) at Python/ceval.c:4324
#24 call_function (oparg=, pp_stack=0x7fffc6b0) at 
Python/ceval.c:4252
#25 PyEval_EvalFrameEx (f=, throwflag=throwflag@entry=0) at 
Python/ceval.c:2829
#26 0x004c5e85 in fast_function (nk=, na=2, n=2, 
pp_stack=0x7fffc890, func=0x72513730) at Python/ceval.c:4324
#27 call_function (oparg=, pp_stack=0x7fffc890) at 
Python/ceval.c:4252
#28 PyEval_EvalFrameEx (f=, throwflag=throwflag@entry=0) at 
Python/ceval.c:2829
#29 0x004c5e85 in fast_function (nk=, na=2, n=2, 
pp_stack=0x7fffca70, func=0x71633378) at Python/ceval.c:4324
#30 call_function (oparg=, pp_stack=0x7fffca70) at 
Python/ceval.c:4252
---Type  to continue, or q  to quit---
#31 PyEval_EvalFrameEx (f=, throwflag=throwflag@entry=0) at 
Python/ceval.c:2829
#32 0x004c5e85 in fast_function (nk=, na=2, n=2, 
pp_stack=0x7fffcc50, func=0x71635d90) at Python/ceval.c:4324
#33 call_function (oparg=, pp_stack=0x7fffcc50) at 
Python/ceval.c:4252
#34 PyEval_EvalFrameEx (f=, throwflag=throwflag@entry=0) at 
Python/ceval.c:2829
#35 0x004c5e85 in fast_function (nk=, na=2, n=2, 
pp_stack=0x7fffce30, func=0x72513730) at Python/ceval.c:4324
#36 call_function (oparg=, pp_stack=0x7fffce30) at 
Python/ceval.c:4252
#37 PyEval_EvalFrameEx (f=, throwflag=throwflag@entry=0) at 
Python/ceval.c:2829
#38 0x004c5e85 in fast_function (nk=, na=2, n=2, 
pp_stack=0x7fffd010, func=0x71633378) at Python/ceval.c:4324
#39 call_function (oparg=, pp_stack=0x7fffd010) at 
Python/ceval.c:4252
#40 PyEval_EvalFrameEx (f=f@entry=0xab9478, throwflag=throwflag@entry=0) at 
Python/ceval.c:2829
#41 0x004be47b in PyEval_EvalCodeEx (_co=, 
globals=, locals=locals@entry=0x0, args=, 
argcount=argcount@entry=1, kws=0xab9380, kwcount=0, defs=0x72504b88, 
defcount=1, kwdefs=0x0, 
closure=0x0) at Python/ceval.c:3578
#42 0x00

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[Antoine Pitrou]

Antoine Pitrou added the comment:

Hi Sebastien,
Those symptoms are actually quite generic. If you want do diagnose your issue, 
I would suggest you compile a debug build of Python (./configure 
--with-pydebug), it will enable many additional checks (and of course be quite 
a bit slower too...).

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[Sebastien Renard]

Sebastien Renard added the comment:

Hi Antoine,
Thanks for your quick answer. I compiled with debug and compile cx_oracle 
again. Here the stack trace with gdb. Hope it will help.


Program received signal SIGSEGV, Segmentation fault.
0x0043ab98 in visit_decref (op=0xb, data=0x0) at 
Modules/gcmodule.c:373
373 if (PyObject_IS_GC(op)) {
(gdb) backtrace
#0  0x0043ab98 in visit_decref (op=0xb, data=0x0) at 
Modules/gcmodule.c:373
#1  0x0048193a in BaseException_traverse (self=0x70f645f8, 
visit=0x43ab64 , arg=0x0) at Objects/exceptions.c:97
#2  0x004dc4cc in subtype_traverse (self=0x70f645f8, visit=0x43ab64 
, arg=0x0) at Objects/typeobject.c:972
#3  0x0043ac8c in subtract_refs (containers=0x8f2ec0 ) at 
Modules/gcmodule.c:398
#4  0x0043bda0 in collect (generation=0, n_collected=0x7ffe6860, 
n_uncollectable=0x7ffe6858, nofail=0) at Modules/gcmodule.c:957
#5  0x0043c409 in collect_with_callback (generation=0) at 
Modules/gcmodule.c:1128
#6  0x0043c4a0 in collect_generations () at Modules/gcmodule.c:1151
#7  0x0043d77c in _PyObject_GC_Malloc (basicsize=48) at 
Modules/gcmodule.c:1726
#8  0x0043d7b4 in _PyObject_GC_New (tp=0x90f980 ) at 
Modules/gcmodule.c:1736
#9  0x0049bec5 in list_iter (seq=0x70f807c8) at 
Objects/listobject.c:2738
#10 0x004620d4 in PyObject_GetIter (o=0x70f807c8) at 
Objects/abstract.c:2656
#11 0x005a4923 in PyEval_EvalFrameEx (f=0xbf4878, throwflag=0) at 
Python/ceval.c:2640
#12 0x005aab83 in PyEval_EvalCodeEx (_co=0x7672fb80, 
globals=0x76721838, locals=0x0, args=0x713c79b0, argcount=2, kws=0x0, 
kwcount=0, defs=0x0, defcount=0, kwdefs=0x0, closure=0x0) at Python/ceval.c:3578
#13 0x0065b49a in function_call (func=0x766f19b0, 
arg=0x713c7988, kw=0x0) at Objects/funcobject.c:632
#14 0x00460069 in PyObject_Call (func=0x766f19b0, 
arg=0x713c7988, kw=0x0) at Objects/abstract.c:2067
#15 0x0047e933 in method_call (func=0x766f19b0, arg=0x713c7988, 
kw=0x0) at Objects/classobject.c:347
#16 0x00460069 in PyObject_Call (func=0x77ebd3d8, 
arg=0x76e30468, kw=0x0) at Objects/abstract.c:2067
#17 0x004dd338 in call_method (o=0x70f7cdc0, nameid=0x91a860 
, format=0x67cd45 "(O)") at Objects/typeobject.c:1394
#18 0x004eb850 in slot_mp_subscript (self=0x70f7cdc0, 
arg1=0x70f86040) at Objects/typeobject.c:5585
#19 0x0045aa4b in PyObject_GetItem (o=0x70f7cdc0, 
key=0x70f86040) at Objects/abstract.c:145
#20 0x005994e0 in PyEval_EvalFrameEx (f=0xbf42f8, throwflag=0) at 
Python/ceval.c:1571
#21 0x005aab83 in PyEval_EvalCodeEx (_co=0x72317d00, 
globals=0x725c6d08, locals=0x0, args=0xbf41b8, argcount=3, kws=0xbf41d0, 
kwcount=0, defs=0x0, defcount=0, kwdefs=0x71c797c8, closure=0x0) at 
Python/ceval.c:3578
#22 0x005adb71 in fast_function (func=0x71c7ba68, 
pp_stack=0x7ffea1b8, n=3, na=3, nk=0) at Python/ceval.c:4334
#23 0x005ad64c in call_function (pp_stack=0x7ffea1b8, oparg=2) at 
Python/ceval.c:4252
#24 0x005a5b37 in PyEval_EvalFrameEx (f=0xbf4018, throwflag=0) at 
Python/ceval.c:2829
#25 0x005ada33 in fast_function (func=0x71c823f0, 
pp_stack=0x7ffebb08, n=2, na=2, nk=0) at Python/ceval.c:4324
#26 0x005ad64c in call_function (pp_stack=0x7ffebb08, oparg=1) at 
Python/ceval.c:4252
#27 0x005a5b37 in PyEval_EvalFrameEx (f=0xd21018, throwflag=0) at 
Python/ceval.c:2829
#28 0x005aab83 in PyEval_EvalCodeEx (_co=0x758f3280, 
globals=0x725db1a8, locals=0x0, args=0xbdcc00, argcount=2, kws=0xbdcc10, 
kwcount=3, defs=0x71ca6440, defcount=3, kwdefs=0x0, closure=0x0) at 
Python/ceval.c:3578
#29 0x005adb71 in fast_function (func=0x71c646d0, 
pp_stack=0x7ffed648, n=8, na=2, nk=3) at Python/ceval.c:4334
#30 0x005ad64c in call_function (pp_stack=0x7ffed648, oparg=770) at 
Python/ceval.c:4252
#31 0x005a5b37 in PyEval_EvalFrameEx (f=0xbdca38, throwflag=0) at 
Python/ceval.c:2829
#32 0x005ada33 in fast_function (func=0x713d36d0, 
pp_stack=0x7ffeef98, n=2, na=2, nk=0) at Python/ceval.c:4324
---Type  to continue, or q  to quit---
#33 0x005ad64c in call_function (pp_stack=0x7ffeef98, oparg=1) at 
Python/ceval.c:4252
#34 0x005a5b37 in PyEval_EvalFrameEx (f=0xd1d118, throwflag=0) at 
Python/ceval.c:2829
#35 0x005ada33 in fast_function (func=0x722e3eb8, 
pp_stack=0x7fff08e8, n=2, na=2, nk=0) at Python/ceval.c:4324
#36 0x005ad64c in call_function (pp_stack=0x7fff08e8, oparg=2) at 
Python/ceval.c:4252
#37 0x005a5b37 in PyEval_EvalFrameEx (f=0xd1c278, throwflag=0) at 
Python/ceval.c:2829
#38 0x005ada33 in fast_function (func=0x713d23f0, 
pp_stack=0x7fff2238, n=2, na=2, nk=0) at Python/ceval.c:4324
#39 0x005ad64c in call

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[Sebastien Renard]

Sebastien Renard added the comment:

Same issue with a fresh python 3.3.5:

361 if (PyObject_IS_GC(op)) {
(gdb) backtrace 
#0  visit_decref (op=0xb, data=data@entry=0x0) at Modules/gcmodule.c:361
#1  0x0052d9da in BaseException_traverse (self=0x7156d328, 
visit=0x4c0800 , arg=0x0) at Objects/exceptions.c:100

Is it a python bug, or could it be an issue with the cx_oracle extension ?

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[Antoine Pitrou]

Antoine Pitrou added the comment:

Well, 0xb is an unlikely pointer value, especially since other 
dynamically-allocated pointers seem to lie in other memory areas. So it would 
look like there's some memory corruption here.

As for whether it's a Python issue, try reproducing without cx_Oracle? If you 
can't, it's likely to be a bug in cx_Oracle.

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[STINNER Victor]

STINNER Victor added the comment:

> I encounter a quite similar issue with python 3.4.0 and cx_Oracle.

Your issue is different, compare the top frames:

My trace:

#0  0x003f3a835c59 in raise () from /lib64/libc.so.6
#1  0x003f3a837368 in abort () from /lib64/libc.so.6
#2  0x003f3a82ebb6 in __assert_fail_base () from /lib64/libc.so.6
#3  0x003f3a82ec62 in __assert_fail () from /lib64/libc.so.6
#4  0x0043ac66 in visit_decref (
op=Frame 0x7f013c001398, for file x.py, line 43 (...) at 
Modules/gcmodule.c:379
#5  0x004336bd in tb_traverse (tb=0x7f01493a66e8, visit=0x43abb4 
, arg=0x0) at Python/traceback.c:64
#6  0x0043acdc in subtract_refs (containers=0x8f1a20 ) 
at Modules/gcmodule.c:398

cx_Oracle trace:

#0  0x0043ab98 in visit_decref (op=0xb, data=0x0) at 
Modules/gcmodule.c:373
#1  0x0048193a in BaseException_traverse (self=0x70f645f8, 
visit=0x43ab64 , arg=0x0) at Objects/exceptions.c:97
#2  0x004dc4cc in subtype_traverse (self=0x70f645f8, visit=0x43ab64 
, arg=0x0) at Objects/typeobject.c:972

In my trace, visit_decref() is called on a frame and fail with an assertion 
error.

In cx_Oracle trace, visit_decref() is called on a NULL pointer which comes from 
an Exception.

In my experience, it's a bug in cx_Oracle. If you think that I'm wrong and that 
it's a bug in Python, please open a *new* issue since the trace is different.

--

For your cx_Oracle, issue:

#1  0x0048193a in BaseException_traverse (self=0x70f645f8, 
visit=0x43ab64 , arg=0x0) at Objects/exceptions.c:97

Can you go this frame (in gdb, type "frame 1") and dump the Exception object:

(gdb) print _PyObject_Dump(0x0048193a)

Note for myself: I should write a documentation explaining how to debug Python 
in gdb.

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[Antoine Pitrou]

Antoine Pitrou added the comment:

> In cx_Oracle trace, visit_decref() is called on a NULL pointer which comes 
> from an Exception.

Unless C conventions changed, 0xb is not a NULL pointer :-)

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[STINNER Victor]

STINNER Victor added the comment:

> Unless C conventions changed, 0xb is not a NULL pointer :-)

Ooops, I missed the B :-)

By the way, my gdb example is wrong: you should pass self :-)

> #1  0x0048193a in BaseException_traverse (self=0x70f645f8, 
> visit=0x43ab64 , arg=0x0) at Objects/exceptions.c:97

=> (gdb) print _PyObject_Dump(0x70f645f8)

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[STINNER Victor]

New submission from STINNER Victor:

While trying to reproduce a race condition in asyncio, I got an assertion error 
from the Python garbage collector at exit. It's not easy to reproduce the 
issue: run attached script on Python 3.4 compiled in debug mode (to get 
assertions) and press CTRL+c twice. It looks like the bug occurs more often 
after at least 400 runs.

The Future class of the asyncio may store an exception in its private 
Future._exception attribute. An exception stores a traceback. I don't know if 
it's related.

Output:
---
...
run #347
^CTraceback (most recent call last):
  File "x.py", line 73, in 
main()
  File "x.py", line 70, in main
el.join()
  File "/home/haypo/prog/python/default/Lib/threading.py", line 1061, in join
self._wait_for_tstate_lock()
  File "/home/haypo/prog/python/default/Lib/threading.py", line 1077, in 
_wait_for_tstate_lock
elif lock.acquire(block, timeout):
run #348
KeyboardInterrupt
...
run #364
run #365
run #366
run #367
-cancelled-
run #368
^CException ignored in: 
Traceback (most recent call last):
  File "/home/haypo/prog/python/default/Lib/threading.py", line 1295, in 
_shutdown
t.join()
  File "/home/haypo/prog/python/default/Lib/threading.py", line 1061, in join
self._wait_for_tstate_lock()
  File "/home/haypo/prog/python/default/Lib/threading.py", line 1077, in 
_wait_for_tstate_lock
elif lock.acquire(block, timeout):
KeyboardInterrupt
-cancelled-
python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> 
(1)) != 0' failed.
Abandon (core dumped)

$ ls *core
python-6564.core

$ gdb ./python -c python-6564.core

Core was generated by `./python x.py'.
Program terminated with signal SIGABRT, Aborted.
(gdb) where
#0  0x003f3a835c59 in raise () from /lib64/libc.so.6
#1  0x003f3a837368 in abort () from /lib64/libc.so.6
#2  0x003f3a82ebb6 in __assert_fail_base () from /lib64/libc.so.6
#3  0x003f3a82ec62 in __assert_fail () from /lib64/libc.so.6
#4  0x0043ac66 in visit_decref (
op=Frame 0x7f013c001398, for file x.py, line 43, in task 
(self=, 
_selector=) at remote 
0x7f014c3bff60>, _epoll=, _fd_to_key={5: 
}) at remote 0x7f014c3bfae8>, 
_granularity=, _ssock=, _internal_fds=1, _csock=, 
_signal_handlers={}) at remote 0x7f014c437400>, _is_stopped=False, 
_target=None, _daemonic=False, executor=, 
acquire=, _lock=<_thread.lock at remote 0x
 7f014c3bb1a0>, _waiters=, arg=0x0) at Python/traceback.c:64
#6  0x0043acdc in subtract_refs (containers=0x8f1a20 ) 
at Modules/gcmodule.c:398
#7  0x0043bdee in collect (generation=2, n_collected=0x7fff499317c0, 
n_uncollectable=0x7fff499317b8, nofail=0)
at Modules/gcmodule.c:957
#8  0x0043c455 in collect_with_callback (generation=2) at 
Modules/gcmodule.c:1128
#9  0x0043d1d5 in PyGC_Collect () at Modules/gcmodule.c:1604
#10 0x0041e959 in Py_Finalize () at Python/pythonrun.c:605
#11 0x0043a890 in Py_Main (argc=2, argv=0x22bb020) at Modules/main.c:771
#12 0x0041aba9 in main (argc=2, argv=0x7fff49931ab8) at 
./Modules/python.c:69

(gdb) frame 4
#4  0x0043ac66 in visit_decref (

(gdb) print op
$3 = Frame 0x7f013c001398, for file x.py, line 43, in task 
(self=, 
_selector=) at remote 
0x7f014c3bff60>, _epoll=, _fd_to_key={5: 
}) at remote 0x7f014c3bfae8>, 
_granularity=, _ssock=, _internal_fds=1, _csock=, 
_signal_handlers={}) at remote 0x7f014c437400>, _is_stopped=False, 
_target=None, _daemonic=False, executor=, 
acquire=, _lock=<_thread.lock at remote 0x7f
 014c3bb1a0>, _waiters=gc.gc_refs >> (1)) != 0' failed.
type: crash
versions: Python 3.4

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[STINNER Victor]

Changes by STINNER Victor :


Added file: http://bugs.python.org/file33939/asyncio_gc.py

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[STINNER Victor]

STINNER Victor added the comment:

At the first CTRL+c, the main thread exit and enters Py_Finalize() which calls 
wait_for_thread_shutdown() (in Python: threading._shutdown()).

The problem is that the second call interrupted threading._shutdown() (still in 
the main thread).

> #9  0x0043d1d5 in PyGC_Collect () at Modules/gcmodule.c:1604
> #10 0x0041e959 in Py_Finalize () at Python/pythonrun.c:605

At this point, we can expect that only one Python thread is running because 
wait_for_thread_shutdown() has been called, but there are between 2 and 9 
running Python threads.

If wait_for_thread_shutdown() is interrupted, maybe Python should kill all 
other threads with pthread_kill() or something like that.

Or wait_for_thread_shutdown() should maybe block SIGINT and SIGTERM signals 
using pthread_sigmark()?

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[Antoine Pitrou]

Antoine Pitrou added the comment:

> If wait_for_thread_shutdown() is interrupted, maybe Python should kill > all 
> other threads with pthread_kill() or something like that.
> 
> Or wait_for_thread_shutdown() should maybe block SIGINT and SIGTERM 
> signals using pthread_sigmark()?

This sounds a bit desperate.
Also, it doesn't explain why collecting the frame crashes. Does the refcount 
become inconsistent?

--
nosy: +neologix

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[Charles-François Natali]

Charles-François Natali added the comment:

Random thoughts:
- executor-created threads are daemon (unfortunately)
- see issue #19466: I think that the change to clear the frame of daemon
threads was a mistake

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[STINNER Victor]

STINNER Victor added the comment:

> Random thoughts:
> - executor-created threads are daemon (unfortunately)

Are you sure? I didn't see the daemon flag in ThreadPoolExecutor.

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[STINNER Victor]

STINNER Victor added the comment:

> Are you sure? I didn't see the daemon flag in ThreadPoolExecutor.

Oh you're right, ThreadPoolExecutor does create daemon threads:

class ThreadPoolExecutor(_base.Executor):
...

def _adjust_thread_count(self):
# When the executor gets lost, the weakref callback will wake up
# the worker threads.
def weakref_cb(_, q=self._work_queue):
q.put(None)
# TODO(bquinlan): Should avoid creating new threads if there are more
# idle threads than items in the work queue.
if len(self._threads) < self._max_workers:
t = threading.Thread(target=_worker,
 args=(weakref.ref(self, weakref_cb),
   self._work_queue))
t.daemon = True   <=== HERE
t.start()
self._threads.add(t)
_threads_queues[t] = self._work_queue

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[STINNER Victor]

STINNER Victor added the comment:

threading_shutdown_interrupted.py: simpler and reliable script to reproduce the 
bug.

--
Added file: http://bugs.python.org/file34053/threading_shutdown_interrupted.py

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[STINNER Victor]

STINNER Victor added the comment:

Charles-François wrote:
> see issue #19466: I think that the change to clear the frame of daemon
> threads was a mistake

Good catch. If I reverted changes of #19466, threading_shutdown_interrupted.py 
doesn't crash anymore.

It doesn't explain how the GC header of a frame object becomes inconsistent.

IMO fixing #19466 was a good idea but because these changes, some bugs became 
more likley.

Maybe we can revert #19466, then try to understand and fix this GC inconstency, 
and later fix again #19466?

--

Oh by the way, threading_shutdown_interrupted.py shows also a deadlock. The 
main threads waits in threading._shutdown(), but this function is interrupted. 
Then it calls flush_std_files() which waits for a lock on stdout. The problem 
is that a thread was writing into stdout, but this thread is no more running 
and holds the lock.

--
nosy: +larry
priority: normal -> release blocker

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[STINNER Victor]

STINNER Victor added the comment:

I set the priority to release blocker because it's a crash, it's a regression 
since Python 3.3 and it can be easily fixed (revert changes done in #19466).

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[STINNER Victor]

STINNER Victor added the comment:

revert_19466.patch: Patch to revert changes of issue #19466. It restores how 
Python cleared threads in Python 3.3.

--
keywords: +patch
Added file: http://bugs.python.org/file34056/revert_19466.patch

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[Arfrever Frehtes Taifersar Arahesis]

Changes by Arfrever Frehtes Taifersar Arahesis :


--
nosy: +Arfrever

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[Guido van Rossum]

Changes by Guido van Rossum :


--
nosy:  -gvanrossum

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[Charles-François Natali]

Charles-François Natali added the comment:

Please revert.

To debug, since I guess it's due to a memory corruption because objects are
deallocated while they're still in use, you could try to use valgrind.
Unfortunately, since it's due to a race condition, the overhead will
probably make it really hard to reproduce :-(

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[Roundup Robot]

Roundup Robot added the comment:

New changeset 1166b3321012 by Victor Stinner in branch 'default':
Issue #20526, #19466: Revert changes of issue #19466 which introduces a
http://hg.python.org/cpython/rev/1166b3321012

--
nosy: +python-dev

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[STINNER Victor]

STINNER Victor added the comment:

> To debug, since I guess it's due to a memory corruption because
> objects are deallocated while they're still in use, you could try
> to use valgrind.
> Unfortunately, since it's due to a race condition, the overhead
> will probably make it really hard to reproduce :-(

I added assert(_Py_Finalizing == NULL || _Py_Finalizing == PyThreadState_GET()) 
almost everywhere, but the assertion didn't fail. It looks like only the main 
thread is running between the interrupted wait_for_thread_shutdown() and the 
final "python: Modules/gcmodule.c:379: visit_decref: ... failed" assertion in 
PyGC_Collect().

I tried to add directly assert(_PyGCHead_REFS(gc) != 0) in 
_PyGCHead_SET_REFS(), but the assertion didn't fail.

I also ran Python in Valgrind: no error neither.

Ok...

I close this issue as won't fix because it was occur with #19466 applied, but I 
just reverted this patch.

--
resolution:  -> wont fix
status: open -> closed

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[STINNER Victor]

STINNER Victor  added the comment:

Right now, threading_shutdown_interrupted.py does crash on the master branch 
(commit 05e4a296ecc127641160a04f39cc02c0f66a8c27). I reintroduced the bug with:

commit 9ad58acbe8b90b4d0f2d2e139e38bb5aa32b7fb6
Author: Victor Stinner 
Date:   Mon Mar 9 23:37:49 2020 +0100

bpo-19466: Py_Finalize() clears daemon threads earlier (GH-18848)

Clear the frames of daemon threads earlier during the Python shutdown to
call objects destructors. So "unclosed file" resource warnings are now
emitted for daemon threads in a more reliable way.

I investigated this bug with Pablo Galindo Salgado. When the bug triggers, 
there are 2 strong references to a Frame object:

* Traceback object
* Generator object

The bug occurs in "except ValueError as exc:" of EvilThread.coroutine().

The exception contains a traceback object which has a strong reference to the 
frame.

The frame object contains "exc" variable (the exception) which contains a 
reference to the tracecback (exc.__traceback__) which contains a refererence to 
the frame (tb.tb_frame): there is a reference cycle. (It's not really an issue 
by itself).

There are 2 strong references to the Frame object.

Py_FinalizeEx() calls _PyThreadState_DeleteExcept() which doesn't clear the 
reference cycle. But PyThreadState_Clear() calls Py_CLEAR(tstate->frame) which 
reduces the Frame reference counter from 2 to 1, even if there are still 2 
strong references to it (traceback and generator).

tstate->frame is only set at 3 places:

* new_threadstate(): when a Python thread state is created (it's initialized to 
NULL)
* _PyEval_EvalFrameDefault() entry: set to frame
* _PyEval_EvalFrameDefault() exit: set to frame->f_back (which can be NULL

By the way, _PyEval_EvalFrameDefault() has a bug: tstate->frame is not reset if 
_PyCode_InitOpcache() fails: bpo-40048.

Py_FinalizeEx() calls _PyRuntimeState_SetFinalizing(runtime, tstate) and so 
threads which tries to take the GIL must exit immediately. Extract of 
take_gil():
---
static inline int
tstate_must_exit(PyThreadState *tstate)
{
PyThreadState *finalizing = _PyRuntimeState_GetFinalizing(&_PyRuntime);
return (finalizing != NULL && finalizing != tstate);
}

static void
take_gil(PyThreadState *tstate)
{
...

if (tstate_must_exit(tstate)) {
PyThread_exit_thread();
}
...
}
---

The thread is exited in the middle of _PyEval_EvalFrameDefault() by take_gil() 
which calls PyThread_exit_thread() because the thread must exit (because the 
main thread destroyed its Python thread state and so accessing it would crash 
the thread).

_PyThreadState_DeleteExcept() calls PyThreadState_Clear() which calls 
Py_CLEAR(tstate->frame): this case only occurs because the thread exited in the 
middle of _PyEval_EvalFrameDefault(). In the normal case, 
_PyEval_EvalFrameDefault() always resets tstate->frame to its previous value.

Py_CLEAR(tstate->frame) is wrong: it's a *borrowed* reference.

Pablo and me agree with PyThreadState_Clear() must not call 
Py_CLEAR(tstate->frame): it's borrowed reference, not a strong reference.

I'm working on a PR to fix the issue.

--
resolution: wont fix -> 
status: closed -> open

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[STINNER Victor]

Change by STINNER Victor :


--
pull_requests: +18481
stage:  -> patch review
pull_request: https://github.com/python/cpython/pull/19120

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[Ned Deily]

Ned Deily  added the comment:

(This issue previously had "release blocker" priority before it was closed.  
Now that it is re-opened does it still need that? I'm assuming not.)

--
nosy: +ned.deily
priority: release blocker -> high
versions: +Python 3.9 -Python 3.4

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[STINNER Victor]

STINNER Victor  added the comment:

> (This issue previously had "release blocker" priority before it was closed.  
> Now that it is re-opened does it still need that? I'm assuming not.)

Techicanilly, it's a 3.9 regression but I don't think that it should be hold 
3.9 release. So no, it's not a blocker issue.

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[STINNER Victor]

STINNER Victor  added the comment:


New changeset 5804f878e779712e803be927ca8a6df389d82cdf by Victor Stinner in 
branch 'master':
bpo-20526: Fix PyThreadState_Clear(): don't decref frame (GH-19120)
https://github.com/python/cpython/commit/5804f878e779712e803be927ca8a6df389d82cdf


--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[STINNER Victor]

Change by STINNER Victor :


--
pull_requests: +18498
pull_request: https://github.com/python/cpython/pull/19136

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[STINNER Victor]

STINNER Victor  added the comment:


New changeset e97c8b0688bc62959ced477d842fcd37992ef649 by Victor Stinner in 
branch '3.8':
bpo-20526: Fix PyThreadState_Clear(): don't decref frame (GH-19120) (GH-19136)
https://github.com/python/cpython/commit/e97c8b0688bc62959ced477d842fcd37992ef649


--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[STINNER Victor]

Change by STINNER Victor :


--
pull_requests: +18499
pull_request: https://github.com/python/cpython/pull/19137

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[STINNER Victor]

STINNER Victor  added the comment:


New changeset d1c09896c3b91d0ad7e3a14fabecde268f70dac7 by Victor Stinner in 
branch '3.7':
bpo-20526: Fix PyThreadState_Clear(): don't decref frame (GH-19120) (GH-19136) 
(GH-19137)
https://github.com/python/cpython/commit/d1c09896c3b91d0ad7e3a14fabecde268f70dac7


--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[STINNER Victor]

STINNER Victor  added the comment:

I ran threading_shutdown_interrupted.py 10 times on the master branch (at 
commit 9b8e74ca77da7167033917d155e5f55c67b92f14): it does no longer crash.

I consider that the root issue is now fixed, so I close again the bug.

Thanks Pablo for the helpful debugging session!

--
components: +Interpreter Core
resolution:  -> fixed
stage: patch review -> resolved
status: open -> closed
versions: +Python 3.7, Python 3.8

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20526] python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.

[STINNER Victor]

STINNER Victor  added the comment:

Just in case, I also ran asyncio_gc.py 10x times on the master branch. I just 
replaced asyncio.async with asyncio.ensure_future. In short, I consider that 
the bug is now fixed.


I interrupted the test two times with CTRL+c. 9 runs were stopped correctly. 1 
run failed with:

Fatal Python error: _enter_buffered_busy: could not acquire lock for 
<_io.BufferedWriter name=''> at interpreter shutdown, possibly due to 
daemon threads

But this is a different issue, unrelated to "Modules/gcmodule.c:379: 
visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed". It's just 
that the test uses print() in threads, whereas using print() during Python 
finalization is not reliable. Using os.write() or avoiding print() would avoid 
the issue.

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com