classification
Title: python: Modules/gcmodule.c:379: visit_decref: Assertion `((gc)->gc.gc_refs >> (1)) != 0' failed.
Type: crash Stage:
Components: Versions: Python 3.4
process
Status: closed Resolution: wont fix
Dependencies: Superseder:
Assigned To: Nosy List: Arfrever, haypo, larry, neologix, pitrou, python-dev, sebastien.renard, serhiy.storchaka
Priority: release blocker Keywords: patch

Created on 2014-02-06 09:14 by haypo, last changed 2014-03-26 10:44 by haypo. This issue is now closed.

Files
File name Uploaded Description Edit
asyncio_gc.py haypo, 2014-02-06 09:14
threading_shutdown_interrupted.py haypo, 2014-02-12 00:19
revert_19466.patch haypo, 2014-02-12 09:54 review
Messages (22)
msg210368 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-02-06 09:14
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 <module>
    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: <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 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  0x0000003f3a835c59 in raise () from /lib64/libc.so.6
#1  0x0000003f3a837368 in abort () from /lib64/libc.so.6
#2  0x0000003f3a82ebb6 in __assert_fail_base () from /lib64/libc.so.6
#3  0x0000003f3a82ec62 in __assert_fail () from /lib64/libc.so.6
#4  0x000000000043ac66 in visit_decref (
    op=Frame 0x7f013c001398, for file x.py, line 43, in task (self=<WorkerThread(_kwargs={}, loop=<_UnixSelectorEventLoop(_scheduled=[], _default_executor=None, _running=True, _ready=<collections.deque at remote 0x7f014bbed6e0>, _selector=<EpollSelector(_map=<_SelectorMapping(_selector=<...>) at remote 0x7f014c3bff60>, _epoll=<select.epoll at remote 0x7f014d5bce08>, _fd_to_key={5: <SelectorKey at remote 0x7f014bbecaf8>}) at remote 0x7f014c3bfae8>, _granularity=<float at remote 0x7f014e8c76b8>, _ssock=<socket at remote 0x7f014c3c5a78>, _internal_fds=1, _csock=<socket at remote 0x7f014bbeb5f8>, _signal_handlers={}) at remote 0x7f014c437400>, _is_stopped=False, _target=None, _daemonic=False, executor=<ThreadPoolExecutor(_max_workers=5, _shutdown=False, _work_queue=<Queue(not_empty=<Condition(release=<built-in method release of _thread.lock object at remote 0x7f014c3bb1a0>, acquire=<built-in method acquire of _thread.lock object at remote 0x7f014c3bb1a0>, _lock=<_thread.lock at remote 0x7f014c3bb1a0>, _waiters=<collecti...(truncated), data=0x0) at Modules/gcmodule.c:379
#5  0x00000000004336bd in tb_traverse (tb=0x7f01493a66e8, visit=0x43abb4 <visit_decref>, arg=0x0) at Python/traceback.c:64
#6  0x000000000043acdc in subtract_refs (containers=0x8f1a20 <generations+64>) at Modules/gcmodule.c:398
#7  0x000000000043bdee in collect (generation=2, n_collected=0x7fff499317c0, n_uncollectable=0x7fff499317b8, nofail=0)
    at Modules/gcmodule.c:957
#8  0x000000000043c455 in collect_with_callback (generation=2) at Modules/gcmodule.c:1128
#9  0x000000000043d1d5 in PyGC_Collect () at Modules/gcmodule.c:1604
#10 0x000000000041e959 in Py_Finalize () at Python/pythonrun.c:605
#11 0x000000000043a890 in Py_Main (argc=2, argv=0x22bb020) at Modules/main.c:771
#12 0x000000000041aba9 in main (argc=2, argv=0x7fff49931ab8) at ./Modules/python.c:69

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

(gdb) print op
$3 = Frame 0x7f013c001398, for file x.py, line 43, in task (self=<WorkerThread(_kwargs={}, loop=<_UnixSelectorEventLoop(_scheduled=[], _default_executor=None, _running=True, _ready=<collections.deque at remote 0x7f014bbed6e0>, _selector=<EpollSelector(_map=<_SelectorMapping(_selector=<...>) at remote 0x7f014c3bff60>, _epoll=<select.epoll at remote 0x7f014d5bce08>, _fd_to_key={5: <SelectorKey at remote 0x7f014bbecaf8>}) at remote 0x7f014c3bfae8>, _granularity=<float at remote 0x7f014e8c76b8>, _ssock=<socket at remote 0x7f014c3c5a78>, _internal_fds=1, _csock=<socket at remote 0x7f014bbeb5f8>, _signal_handlers={}) at remote 0x7f014c437400>, _is_stopped=False, _target=None, _daemonic=False, executor=<ThreadPoolExecutor(_max_workers=5, _shutdown=False, _work_queue=<Queue(not_empty=<Condition(release=<built-in method release of _thread.lock object at remote 0x7f014c3bb1a0>, acquire=<built-in method acquire of _thread.lock object at remote 0x7f014c3bb1a0>, _lock=<_thread.lock at remote 0x7f014c3bb1a0>, _waiters=<collecti...(truncated)
---
msg210982 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-02-11 17:30
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  0x000000000043d1d5 in PyGC_Collect () at Modules/gcmodule.c:1604
> #10 0x000000000041e959 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()?
msg210999 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2014-02-11 19:00
> 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?
msg211007 - (view) Author: Charles-François Natali (neologix) * (Python committer) Date: 2014-02-11 19:47
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
msg211013 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-02-11 20:35
> Random thoughts:
> - executor-created threads are daemon (unfortunately)

Are you sure? I didn't see the daemon flag in ThreadPoolExecutor.
msg211046 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-02-12 00:00
> 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
msg211047 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-02-12 00:19
threading_shutdown_interrupted.py: simpler and reliable script to reproduce the bug.
msg211049 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-02-12 00:35
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.
msg211050 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-02-12 00:37
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).
msg211070 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-02-12 09:54
revert_19466.patch: Patch to revert changes of issue #19466. It restores how Python cleared threads in Python 3.3.
msg211146 - (view) Author: Charles-François Natali (neologix) * (Python committer) Date: 2014-02-13 11:24
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 :-(
msg211150 - (view) Author: Roundup Robot (python-dev) Date: 2014-02-13 11:52
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
msg211153 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-02-13 13:33
> 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.
msg213793 - (view) Author: Roundup Robot (python-dev) Date: 2014-03-17 06:30
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
msg214858 - (view) Author: Sebastien Renard (sebastien.renard) Date: 2014-03-25 22:04
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 
* 1    Thread 0x7ffff7fc6740 (LWP 7415) "python3" visit_decref (op=0xb00000000, data=data@entry=0x0) at Modules/gcmodule.c:373
(gdb) backtrace 
#0  visit_decref (op=0xb00000000, data=data@entry=0x0) at Modules/gcmodule.c:373
#1  0x00000000004318da in BaseException_traverse (self=0x7ffff1624888, visit=0x504660 <visit_decref>, arg=0x0) at Objects/exceptions.c:97
#2  0x0000000000504925 in subtract_refs (containers=<optimized out>) at Modules/gcmodule.c:398
#3  collect (generation=generation@entry=0, n_collected=n_collected@entry=0x7fffffffbd60, n_uncollectable=n_uncollectable@entry=0x7fffffffbd68, nofail=nofail@entry=0) at Modules/gcmodule.c:957
#4  0x0000000000505573 in collect_with_callback (generation=0) at Modules/gcmodule.c:1128
#5  collect_generations () at Modules/gcmodule.c:1151
#6  0x0000000000505cd1 in _PyObject_GC_Malloc (basicsize=<optimized out>) at Modules/gcmodule.c:1726
#7  _PyObject_GC_Malloc (basicsize=<optimized out>) at Modules/gcmodule.c:1743
#8  _PyObject_GC_NewVar (tp=tp@entry=0x810400 <PyTuple_Type>, nitems=nitems@entry=11) at Modules/gcmodule.c:1753
#9  0x000000000046470c in PyTuple_New (size=11) at Objects/tupleobject.c:104
#10 0x0000000000464e05 in PyTuple_New (size=size@entry=11) at Objects/tupleobject.c:122
#11 0x00007ffff582e881 in Cursor_CreateRow (self=self@entry=0x7ffff1603290) at Cursor.c:1095
#12 0x00007ffff582f18f in Cursor_MultiFetch (self=0x7ffff1603290, rowLimit=0) at Cursor.c:1883
#13 0x00000000004c4aa7 in call_function (oparg=<optimized out>, pp_stack=0x7fffffffbfb0) at Python/ceval.c:4210
#14 PyEval_EvalFrameEx (f=f@entry=0xab5208, throwflag=throwflag@entry=0) at Python/ceval.c:2829
#15 0x00000000004be47b in PyEval_EvalCodeEx (_co=<optimized out>, globals=<optimized out>, locals=locals@entry=0x0, args=<optimized out>, argcount=argcount@entry=3, kws=0x7ffff11c3ad8, kwcount=0, defs=0x7ffff5a635a0, defcount=1, kwdefs=0x0, 
    closure=0x0) at Python/ceval.c:3578
#16 0x00000000004c3d91 in fast_function (nk=<optimized out>, na=3, n=<optimized out>, pp_stack=0x7fffffffc240, func=0x7ffff1e98b70) at Python/ceval.c:4334
#17 call_function (oparg=<optimized out>, pp_stack=0x7fffffffc240) at Python/ceval.c:4252
#18 PyEval_EvalFrameEx (f=f@entry=0x7ffff11c3930, throwflag=throwflag@entry=0) at Python/ceval.c:2829
#19 0x00000000004be47b in PyEval_EvalCodeEx (_co=<optimized out>, globals=<optimized out>, locals=locals@entry=0x0, args=<optimized out>, argcount=argcount@entry=2, kws=0xbf7610, kwcount=1, defs=0x7ffff1eb14c0, defcount=1, kwdefs=0x0, 
    closure=0x0) at Python/ceval.c:3578
#20 0x00000000004c3d91 in fast_function (nk=<optimized out>, na=2, n=<optimized out>, pp_stack=0x7fffffffc4d0, func=0x7ffff160b510) at Python/ceval.c:4334
#21 call_function (oparg=<optimized out>, pp_stack=0x7fffffffc4d0) at Python/ceval.c:4252
#22 PyEval_EvalFrameEx (f=<optimized out>, throwflag=throwflag@entry=0) at Python/ceval.c:2829
#23 0x00000000004c5e85 in fast_function (nk=<optimized out>, na=2, n=2, pp_stack=0x7fffffffc6b0, func=0x7ffff1634d08) at Python/ceval.c:4324
#24 call_function (oparg=<optimized out>, pp_stack=0x7fffffffc6b0) at Python/ceval.c:4252
#25 PyEval_EvalFrameEx (f=<optimized out>, throwflag=throwflag@entry=0) at Python/ceval.c:2829
#26 0x00000000004c5e85 in fast_function (nk=<optimized out>, na=2, n=2, pp_stack=0x7fffffffc890, func=0x7ffff2513730) at Python/ceval.c:4324
#27 call_function (oparg=<optimized out>, pp_stack=0x7fffffffc890) at Python/ceval.c:4252
#28 PyEval_EvalFrameEx (f=<optimized out>, throwflag=throwflag@entry=0) at Python/ceval.c:2829
#29 0x00000000004c5e85 in fast_function (nk=<optimized out>, na=2, n=2, pp_stack=0x7fffffffca70, func=0x7ffff1633378) at Python/ceval.c:4324
#30 call_function (oparg=<optimized out>, pp_stack=0x7fffffffca70) at Python/ceval.c:4252
---Type <return> to continue, or q <return> to quit---
#31 PyEval_EvalFrameEx (f=<optimized out>, throwflag=throwflag@entry=0) at Python/ceval.c:2829
#32 0x00000000004c5e85 in fast_function (nk=<optimized out>, na=2, n=2, pp_stack=0x7fffffffcc50, func=0x7ffff1635d90) at Python/ceval.c:4324
#33 call_function (oparg=<optimized out>, pp_stack=0x7fffffffcc50) at Python/ceval.c:4252
#34 PyEval_EvalFrameEx (f=<optimized out>, throwflag=throwflag@entry=0) at Python/ceval.c:2829
#35 0x00000000004c5e85 in fast_function (nk=<optimized out>, na=2, n=2, pp_stack=0x7fffffffce30, func=0x7ffff2513730) at Python/ceval.c:4324
#36 call_function (oparg=<optimized out>, pp_stack=0x7fffffffce30) at Python/ceval.c:4252
#37 PyEval_EvalFrameEx (f=<optimized out>, throwflag=throwflag@entry=0) at Python/ceval.c:2829
#38 0x00000000004c5e85 in fast_function (nk=<optimized out>, na=2, n=2, pp_stack=0x7fffffffd010, func=0x7ffff1633378) at Python/ceval.c:4324
#39 call_function (oparg=<optimized out>, pp_stack=0x7fffffffd010) at Python/ceval.c:4252
#40 PyEval_EvalFrameEx (f=f@entry=0xab9478, throwflag=throwflag@entry=0) at Python/ceval.c:2829
#41 0x00000000004be47b in PyEval_EvalCodeEx (_co=<optimized out>, globals=<optimized out>, locals=locals@entry=0x0, args=<optimized out>, argcount=argcount@entry=1, kws=0xab9380, kwcount=0, defs=0x7ffff2504b88, defcount=1, kwdefs=0x0, 
    closure=0x0) at Python/ceval.c:3578
#42 0x00000000004c3d91 in fast_function (nk=<optimized out>, na=1, n=<optimized out>, pp_stack=0x7fffffffd2a0, func=0x7ffff2513400) at Python/ceval.c:4334
#43 call_function (oparg=<optimized out>, pp_stack=0x7fffffffd2a0) at Python/ceval.c:4252
#44 PyEval_EvalFrameEx (f=<optimized out>, throwflag=throwflag@entry=0) at Python/ceval.c:2829
#45 0x00000000004c5e85 in fast_function (nk=<optimized out>, na=1, n=1, pp_stack=0x7fffffffd480, func=0x7ffff16331e0) at Python/ceval.c:4324
#46 call_function (oparg=<optimized out>, pp_stack=0x7fffffffd480) at Python/ceval.c:4252
#47 PyEval_EvalFrameEx (f=<optimized out>, throwflag=throwflag@entry=0) at Python/ceval.c:2829
#48 0x00000000004c5e85 in fast_function (nk=<optimized out>, na=0, n=0, pp_stack=0x7fffffffd660, func=0x7ffff6ed4d08) at Python/ceval.c:4324
#49 call_function (oparg=<optimized out>, pp_stack=0x7fffffffd660) at Python/ceval.c:4252
#50 PyEval_EvalFrameEx (f=f@entry=0x7ffff7eceaf8, throwflag=throwflag@entry=0) at Python/ceval.c:2829
#51 0x00000000004be47b in PyEval_EvalCodeEx (_co=_co@entry=0x7ffff6ed14b0, globals=globals@entry=0x7ffff7ef1388, locals=locals@entry=0x7ffff7ef1388, args=args@entry=0x0, argcount=argcount@entry=0, kws=kws@entry=0x0, kwcount=kwcount@entry=0, 
    defs=defs@entry=0x0, defcount=defcount@entry=0, kwdefs=kwdefs@entry=0x0, closure=closure@entry=0x0) at Python/ceval.c:3578
#52 0x00000000004be54b in PyEval_EvalCode (co=co@entry=0x7ffff6ed14b0, globals=globals@entry=0x7ffff7ef1388, locals=locals@entry=0x7ffff7ef1388) at Python/ceval.c:773
#53 0x00000000004ed844 in run_mod (arena=0x8fea30, flags=0x7fffffffd910, locals=0x7ffff7ef1388, globals=0x7ffff7ef1388, filename=0x7ffff7ea7a78, mod=0x97c090) at Python/pythonrun.c:2175
#54 PyRun_InteractiveOneObject (fp=fp@entry=0x7ffff74b6340 <_IO_2_1_stdin_>, filename=filename@entry=0x7ffff7ea7a78, flags=flags@entry=0x7fffffffd910) at Python/pythonrun.c:1441
#55 0x00000000004edb7e in PyRun_InteractiveLoopFlags (fp=fp@entry=0x7ffff74b6340 <_IO_2_1_stdin_>, filename_str=filename_str@entry=0x580d63 "<stdin>", flags=flags@entry=0x7fffffffd910) at Python/pythonrun.c:1320
#56 0x00000000004edcd6 in PyRun_AnyFileExFlags (fp=fp@entry=0x7ffff74b6340 <_IO_2_1_stdin_>, filename=<optimized out>, closeit=0, flags=flags@entry=0x7fffffffd910) at Python/pythonrun.c:1282
#57 0x000000000041e243 in run_file (p_cf=0x7fffffffd910, filename=0x0, fp=0x7ffff74b6340 <_IO_2_1_stdin_>) at Modules/main.c:319
#58 Py_Main (argc=argc@entry=1, argv=argv@entry=0x872010) at Modules/main.c:751
#59 0x000000000041aacc in main (argc=1, argv=<optimized out>) at ./Modules/python.c:69
(gdb) 


Regards
msg214859 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2014-03-25 22:16
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...).
msg214863 - (view) Author: Sebastien Renard (sebastien.renard) Date: 2014-03-25 23:10
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.
0x000000000043ab98 in visit_decref (op=0xb00000000, data=0x0) at Modules/gcmodule.c:373
373         if (PyObject_IS_GC(op)) {
(gdb) backtrace
#0  0x000000000043ab98 in visit_decref (op=0xb00000000, data=0x0) at Modules/gcmodule.c:373
#1  0x000000000048193a in BaseException_traverse (self=0x7ffff0f645f8, visit=0x43ab64 <visit_decref>, arg=0x0) at Objects/exceptions.c:97
#2  0x00000000004dc4cc in subtype_traverse (self=0x7ffff0f645f8, visit=0x43ab64 <visit_decref>, arg=0x0) at Objects/typeobject.c:972
#3  0x000000000043ac8c in subtract_refs (containers=0x8f2ec0 <generations>) at Modules/gcmodule.c:398
#4  0x000000000043bda0 in collect (generation=0, n_collected=0x7ffffffe6860, n_uncollectable=0x7ffffffe6858, nofail=0) at Modules/gcmodule.c:957
#5  0x000000000043c409 in collect_with_callback (generation=0) at Modules/gcmodule.c:1128
#6  0x000000000043c4a0 in collect_generations () at Modules/gcmodule.c:1151
#7  0x000000000043d77c in _PyObject_GC_Malloc (basicsize=48) at Modules/gcmodule.c:1726
#8  0x000000000043d7b4 in _PyObject_GC_New (tp=0x90f980 <PyListIter_Type>) at Modules/gcmodule.c:1736
#9  0x000000000049bec5 in list_iter (seq=0x7ffff0f807c8) at Objects/listobject.c:2738
#10 0x00000000004620d4 in PyObject_GetIter (o=0x7ffff0f807c8) at Objects/abstract.c:2656
#11 0x00000000005a4923 in PyEval_EvalFrameEx (f=0xbf4878, throwflag=0) at Python/ceval.c:2640
#12 0x00000000005aab83 in PyEval_EvalCodeEx (_co=0x7ffff672fb80, globals=0x7ffff6721838, locals=0x0, args=0x7ffff13c79b0, argcount=2, kws=0x0, kwcount=0, defs=0x0, defcount=0, kwdefs=0x0, closure=0x0) at Python/ceval.c:3578
#13 0x000000000065b49a in function_call (func=0x7ffff66f19b0, arg=0x7ffff13c7988, kw=0x0) at Objects/funcobject.c:632
#14 0x0000000000460069 in PyObject_Call (func=0x7ffff66f19b0, arg=0x7ffff13c7988, kw=0x0) at Objects/abstract.c:2067
#15 0x000000000047e933 in method_call (func=0x7ffff66f19b0, arg=0x7ffff13c7988, kw=0x0) at Objects/classobject.c:347
#16 0x0000000000460069 in PyObject_Call (func=0x7ffff7ebd3d8, arg=0x7ffff6e30468, kw=0x0) at Objects/abstract.c:2067
#17 0x00000000004dd338 in call_method (o=0x7ffff0f7cdc0, nameid=0x91a860 <id.11627>, format=0x67cd45 "(O)") at Objects/typeobject.c:1394
#18 0x00000000004eb850 in slot_mp_subscript (self=0x7ffff0f7cdc0, arg1=0x7ffff0f86040) at Objects/typeobject.c:5585
#19 0x000000000045aa4b in PyObject_GetItem (o=0x7ffff0f7cdc0, key=0x7ffff0f86040) at Objects/abstract.c:145
#20 0x00000000005994e0 in PyEval_EvalFrameEx (f=0xbf42f8, throwflag=0) at Python/ceval.c:1571
#21 0x00000000005aab83 in PyEval_EvalCodeEx (_co=0x7ffff2317d00, globals=0x7ffff25c6d08, locals=0x0, args=0xbf41b8, argcount=3, kws=0xbf41d0, kwcount=0, defs=0x0, defcount=0, kwdefs=0x7ffff1c797c8, closure=0x0) at Python/ceval.c:3578
#22 0x00000000005adb71 in fast_function (func=0x7ffff1c7ba68, pp_stack=0x7ffffffea1b8, n=3, na=3, nk=0) at Python/ceval.c:4334
#23 0x00000000005ad64c in call_function (pp_stack=0x7ffffffea1b8, oparg=2) at Python/ceval.c:4252
#24 0x00000000005a5b37 in PyEval_EvalFrameEx (f=0xbf4018, throwflag=0) at Python/ceval.c:2829
#25 0x00000000005ada33 in fast_function (func=0x7ffff1c823f0, pp_stack=0x7ffffffebb08, n=2, na=2, nk=0) at Python/ceval.c:4324
#26 0x00000000005ad64c in call_function (pp_stack=0x7ffffffebb08, oparg=1) at Python/ceval.c:4252
#27 0x00000000005a5b37 in PyEval_EvalFrameEx (f=0xd21018, throwflag=0) at Python/ceval.c:2829
#28 0x00000000005aab83 in PyEval_EvalCodeEx (_co=0x7ffff58f3280, globals=0x7ffff25db1a8, locals=0x0, args=0xbdcc00, argcount=2, kws=0xbdcc10, kwcount=3, defs=0x7ffff1ca6440, defcount=3, kwdefs=0x0, closure=0x0) at Python/ceval.c:3578
#29 0x00000000005adb71 in fast_function (func=0x7ffff1c646d0, pp_stack=0x7ffffffed648, n=8, na=2, nk=3) at Python/ceval.c:4334
#30 0x00000000005ad64c in call_function (pp_stack=0x7ffffffed648, oparg=770) at Python/ceval.c:4252
#31 0x00000000005a5b37 in PyEval_EvalFrameEx (f=0xbdca38, throwflag=0) at Python/ceval.c:2829
#32 0x00000000005ada33 in fast_function (func=0x7ffff13d36d0, pp_stack=0x7ffffffeef98, n=2, na=2, nk=0) at Python/ceval.c:4324
---Type <return> to continue, or q <return> to quit---
#33 0x00000000005ad64c in call_function (pp_stack=0x7ffffffeef98, oparg=1) at Python/ceval.c:4252
#34 0x00000000005a5b37 in PyEval_EvalFrameEx (f=0xd1d118, throwflag=0) at Python/ceval.c:2829
#35 0x00000000005ada33 in fast_function (func=0x7ffff22e3eb8, pp_stack=0x7fffffff08e8, n=2, na=2, nk=0) at Python/ceval.c:4324
#36 0x00000000005ad64c in call_function (pp_stack=0x7fffffff08e8, oparg=2) at Python/ceval.c:4252
#37 0x00000000005a5b37 in PyEval_EvalFrameEx (f=0xd1c278, throwflag=0) at Python/ceval.c:2829
#38 0x00000000005ada33 in fast_function (func=0x7ffff13d23f0, pp_stack=0x7fffffff2238, n=2, na=2, nk=0) at Python/ceval.c:4324
#39 0x00000000005ad64c in call_function (pp_stack=0x7fffffff2238, oparg=1) at Python/ceval.c:4252
#40 0x00000000005a5b37 in PyEval_EvalFrameEx (f=0xcda7d8, throwflag=0) at Python/ceval.c:2829
#41 0x00000000005ada33 in fast_function (func=0x7ffff13d5bd8, pp_stack=0x7fffffff3b88, n=2, na=2, nk=0) at Python/ceval.c:4324
#42 0x00000000005ad64c in call_function (pp_stack=0x7fffffff3b88, oparg=1) at Python/ceval.c:4252
#43 0x00000000005a5b37 in PyEval_EvalFrameEx (f=0xbf5558, throwflag=0) at Python/ceval.c:2829
#44 0x00000000005ada33 in fast_function (func=0x7ffff22e3eb8, pp_stack=0x7fffffff54d8, n=2, na=2, nk=0) at Python/ceval.c:4324
#45 0x00000000005ad64c in call_function (pp_stack=0x7fffffff54d8, oparg=2) at Python/ceval.c:4252
#46 0x00000000005a5b37 in PyEval_EvalFrameEx (f=0xb945b8, throwflag=0) at Python/ceval.c:2829
#47 0x00000000005ada33 in fast_function (func=0x7ffff13d23f0, pp_stack=0x7fffffff6e28, n=2, na=2, nk=0) at Python/ceval.c:4324
#48 0x00000000005ad64c in call_function (pp_stack=0x7fffffff6e28, oparg=1) at Python/ceval.c:4252
#49 0x00000000005a5b37 in PyEval_EvalFrameEx (f=0xbf37a8, throwflag=0) at Python/ceval.c:2829
#50 0x00000000005aab83 in PyEval_EvalCodeEx (_co=0x7ffff234f700, globals=0x7ffff234dfa8, locals=0x0, args=0xbf3668, argcount=1, kws=0xbf3670, kwcount=0, defs=0x7ffff2352c48, defcount=1, kwdefs=0x0, closure=0x0) at Python/ceval.c:3578
#51 0x00000000005adb71 in fast_function (func=0x7ffff22e3a68, pp_stack=0x7fffffff8968, n=1, na=1, nk=0) at Python/ceval.c:4334
#52 0x00000000005ad64c in call_function (pp_stack=0x7fffffff8968, oparg=0) at Python/ceval.c:4252
#53 0x00000000005a5b37 in PyEval_EvalFrameEx (f=0xbf34c8, throwflag=0) at Python/ceval.c:2829
#54 0x00000000005ada33 in fast_function (func=0x7ffff13d21c8, pp_stack=0x7fffffffa2b8, n=1, na=1, nk=0) at Python/ceval.c:4324
#55 0x00000000005ad64c in call_function (pp_stack=0x7fffffffa2b8, oparg=0) at Python/ceval.c:4252
#56 0x00000000005a5b37 in PyEval_EvalFrameEx (f=0xab0208, throwflag=0) at Python/ceval.c:2829
#57 0x00000000005ada33 in fast_function (func=0x7ffff6e106d0, pp_stack=0x7fffffffbc08, n=0, na=0, nk=0) at Python/ceval.c:4324
#58 0x00000000005ad64c in call_function (pp_stack=0x7fffffffbc08, oparg=0) at Python/ceval.c:4252
#59 0x00000000005a5b37 in PyEval_EvalFrameEx (f=0xa12bc8, throwflag=0) at Python/ceval.c:2829
#60 0x00000000005aab83 in PyEval_EvalCodeEx (_co=0x7ffff6e2e7c0, globals=0x7ffff7eb9ad8, locals=0x7ffff7eb9ad8, args=0x0, argcount=0, kws=0x0, kwcount=0, defs=0x0, defcount=0, kwdefs=0x0, closure=0x0) at Python/ceval.c:3578
#61 0x0000000000596405 in PyEval_EvalCode (co=0x7ffff6e2e7c0, globals=0x7ffff7eb9ad8, locals=0x7ffff7eb9ad8) at Python/ceval.c:773
#62 0x00000000004239ae in run_mod (mod=0xa9a180, filename=0x7ffff7e18380, globals=0x7ffff7eb9ad8, locals=0x7ffff7eb9ad8, flags=0x7fffffffd910, arena=0xa98800) at Python/pythonrun.c:2175
#63 0x0000000000420df9 in PyRun_InteractiveOneObject (fp=0x7ffff74b6340 <_IO_2_1_stdin_>, filename=0x7ffff7e18380, flags=0x7fffffffd910) at Python/pythonrun.c:1441
#64 0x00000000004206fd in PyRun_InteractiveLoopFlags (fp=0x7ffff74b6340 <_IO_2_1_stdin_>, filename_str=0x661936 "<stdin>", flags=0x7fffffffd910) at Python/pythonrun.c:1320
#65 0x00000000004204f3 in PyRun_AnyFileExFlags (fp=0x7ffff74b6340 <_IO_2_1_stdin_>, filename=0x661936 "<stdin>", closeit=0, flags=0x7fffffffd910) at Python/pythonrun.c:1282
---Type <return> to continue, or q <return> to quit---
#66 0x0000000000439b4f in run_file (fp=0x7ffff74b6340 <_IO_2_1_stdin_>, filename=0x0, p_cf=0x7fffffffd910) at Modules/main.c:319
#67 0x000000000043a791 in Py_Main (argc=1, argv=0x975020) at Modules/main.c:751
#68 0x000000000041aa19 in main (argc=1, argv=0x7fffffffdb08) at ./Modules/python.c:69
(gdb)
msg214866 - (view) Author: Sebastien Renard (sebastien.renard) Date: 2014-03-25 23:27
Same issue with a fresh python 3.3.5:

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

Is it a python bug, or could it be an issue with the cx_oracle extension ?
msg214867 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2014-03-25 23:30
Well, 0xb00000000 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.
msg214887 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-03-26 10:20
> 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  0x0000003f3a835c59 in raise () from /lib64/libc.so.6
#1  0x0000003f3a837368 in abort () from /lib64/libc.so.6
#2  0x0000003f3a82ebb6 in __assert_fail_base () from /lib64/libc.so.6
#3  0x0000003f3a82ec62 in __assert_fail () from /lib64/libc.so.6
#4  0x000000000043ac66 in visit_decref (
    op=Frame 0x7f013c001398, for file x.py, line 43 (...) at Modules/gcmodule.c:379
#5  0x00000000004336bd in tb_traverse (tb=0x7f01493a66e8, visit=0x43abb4 <visit_decref>, arg=0x0) at Python/traceback.c:64
#6  0x000000000043acdc in subtract_refs (containers=0x8f1a20 <generations+64>) at Modules/gcmodule.c:398

cx_Oracle trace:

#0  0x000000000043ab98 in visit_decref (op=0xb00000000, data=0x0) at Modules/gcmodule.c:373
#1  0x000000000048193a in BaseException_traverse (self=0x7ffff0f645f8, visit=0x43ab64 <visit_decref>, arg=0x0) at Objects/exceptions.c:97
#2  0x00000000004dc4cc in subtype_traverse (self=0x7ffff0f645f8, visit=0x43ab64 <visit_decref>, 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  0x000000000048193a in BaseException_traverse (self=0x7ffff0f645f8, visit=0x43ab64 <visit_decref>, 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(0x000000000048193a)

Note for myself: I should write a documentation explaining how to debug Python in gdb.
msg214890 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2014-03-26 10:36
> In cx_Oracle trace, visit_decref() is called on a NULL pointer which comes from an Exception.

Unless C conventions changed, 0xb00000000 is not a NULL pointer :-)
msg214894 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-03-26 10:44
> Unless C conventions changed, 0xb00000000 is not a NULL pointer :-)

Ooops, I missed the B :-)

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

> #1  0x000000000048193a in BaseException_traverse (self=0x7ffff0f645f8, visit=0x43ab64 <visit_decref>, arg=0x0) at Objects/exceptions.c:97

=> (gdb) print _PyObject_Dump(0x7ffff0f645f8)
History
Date User Action Args
2014-03-26 10:44:29hayposetmessages: + msg214894
2014-03-26 10:36:00pitrousetmessages: + msg214890
2014-03-26 10:20:45hayposetmessages: + msg214887
2014-03-25 23:30:08pitrousetmessages: + msg214867
2014-03-25 23:27:18sebastien.renardsetmessages: + msg214866
2014-03-25 23:10:02sebastien.renardsetmessages: + msg214863
2014-03-25 22:16:59pitrousetmessages: + msg214859
2014-03-25 22:04:29sebastien.renardsetnosy: + sebastien.renard
messages: + msg214858
2014-03-17 06:30:40python-devsetmessages: + msg213793
2014-02-13 13:33:49hayposetstatus: open -> closed
resolution: wont fix
messages: + msg211153
2014-02-13 11:52:30python-devsetnosy: + python-dev
messages: + msg211150
2014-02-13 11:24:07neologixsetmessages: + msg211146
2014-02-12 16:23:19gvanrossumsetnosy: - gvanrossum
2014-02-12 09:57:35Arfreversetnosy: + Arfrever
2014-02-12 09:54:11hayposetfiles: + revert_19466.patch
keywords: + patch
messages: + msg211070
2014-02-12 00:37:40hayposetmessages: + msg211050
2014-02-12 00:35:54hayposetpriority: normal -> release blocker
nosy: + larry
messages: + msg211049

2014-02-12 00:19:20hayposetfiles: + threading_shutdown_interrupted.py

messages: + msg211047
2014-02-12 00:00:15hayposetmessages: + msg211046
2014-02-11 20:35:19hayposetmessages: + msg211013
2014-02-11 19:47:08neologixsetmessages: + msg211007
2014-02-11 19:00:16pitrousetnosy: + neologix
messages: + msg210999
2014-02-11 17:30:49hayposetmessages: + msg210982
2014-02-06 09:14:14hayposetfiles: + asyncio_gc.py
2014-02-06 09:14:02haypocreate