Debugging python segmentation faults in garbage collection
<p>I'm faced with segmentation faults (SIGSEGV) which occur during garbage collection in cPython. I've also had one instance where a process was killed with SIGBUS. My own code is mostly python and a little bit of very high level Cython. I'm most certainly not - deliberately and explicitly - fooling around with pointers or writing to memory directly.</p>

<hr>

<p>Example backtraces from coredumps (extracted with gdb):</p>

<pre><code>#0  0x00007f8b0ac29471 in subtype_dealloc (self=&lt;Task at remote 0x7f8afc0466d8&gt;)
    at /usr/src/debug/Python-3.5.1/Objects/typeobject.c:1182
#1  0x00007f8b0abe8947 in method_dealloc (im=0x7f8afc883e08) at /usr/src/debug/Python-3.5.1/Objects/classobject.c:198
#2  0x00007f8b0ac285a9 in clear_slots (type=type@entry=0x560219f0fa88, 
    self=self@entry=&lt;Handle at remote 0x7f8afc035948&gt;) at /usr/src/debug/Python-3.5.1/Objects/typeobject.c:1044
#3  0x00007f8b0ac29506 in subtype_dealloc (self=&lt;Handle at remote 0x7f8afc035948&gt;)
    at /usr/src/debug/Python-3.5.1/Objects/typeobject.c:1200
#4  0x00007f8b0ac8caad in PyEval_EvalFrameEx (
    f=f@entry=Frame 0x56021a01ff08, for file /usr/lib64/python3.5/asyncio/base_events.py, line 1239, in _run_once (self=&lt;_UnixSelectorEventLoop(_coroutine_wrapper_set=False, _current_handle=None, _ready=&lt;collections.deque at remote 0x7f8afd39a250&gt;, _closed=False, _task_factory=None, _selector=&lt;EpollSelector(_map=&lt;_SelectorMapping(_selector=&lt;...&gt;) at remote 0x7f8afc868748&gt;, _epoll=&lt;select.epoll at remote 0x7f8b0b1b8e58&gt;, _fd_to_key={4: &lt;SelectorKey at remote 0x7f8afcac8a98&gt;, 6: &lt;SelectorKey at remote 0x7f8afcac8e08&gt;, 7: &lt;SelectorKey at remote 0x7f8afcac8e60&gt;, 8: &lt;SelectorKey at remote 0x7f8afc873048&gt;, 9: &lt;SelectorKey at remote 0x7f8afc873830&gt;, 10: &lt;SelectorKey at remote 0x7f8afc873af0&gt;, 11: &lt;SelectorKey at remote 0x7f8afc87b620&gt;, 12: &lt;SelectorKey at remote 0x7f8afc87b7d8&gt;, 13: &lt;SelectorKey at remote 0x7f8afc889af0&gt;, 14: &lt;SelectorKey at remote 0x7f8afc884678&gt;, 15: &lt;SelectorKey at remote 0x7f8afc025eb8&gt;, 16: &lt;SelectorKey at remote 0x7f8afc889db0&gt;, 17: &lt;SelectorKey at remote 0x7f8afc01a258&gt;, 18: &lt;SelectorKey at remote 0x7f8afc...(truncated), 
    throwflag=throwflag@entry=0) at /usr/src/debug/Python-3.5.1/Python/ceval.c:1414
</code></pre>

<p>During the sweep (I think):</p>

<pre><code>#1  0x00007f0a0624c63f in visit_decref (op=, data=&lt;optimized out&gt;)
    at /usr/src/debug/Python-3.5.1/Modules/gcmodule.c:373
#2  0x00007f0a0624b813 in subtract_refs (containers=&lt;optimized out&gt;)
    at /usr/src/debug/Python-3.5.1/Modules/gcmodule.c:398
#3  collect (generation=generation@entry=2, n_collected=n_collected@entry=0x7f09d75708c8, 
    n_uncollectable=n_uncollectable@entry=0x7f09d75708d0, nofail=nofail@entry=0)
    at /usr/src/debug/Python-3.5.1/Modules/gcmodule.c:951
</code></pre>

<p>And also once during malloc:</p>

<pre><code>#0  _PyObject_Malloc (ctx=0x0, nbytes=56) at /usr/src/debug/Python-3.4.3/Objects/obmalloc.c:1159
1159                if ((pool-&gt;freeblock = *(block **)bp) != NULL) {
(gdb) bt
#0  _PyObject_Malloc (ctx=0x0, nbytes=56) at /usr/src/debug/Python-3.4.3/Objects/obmalloc.c:1159
</code></pre>

<p>And the SIGBUS trace (looks like it happened while cPython was recovering from another error):</p>

<pre><code>#0  malloc_printerr (ar_ptr=0x100101f0100101a, ptr=0x7f067955da60 &lt;generations+32&gt;, str=0x7f06785a2b8c "free(): invalid size", action=3) at malloc.c:5009
5009        set_arena_corrupt (ar_ptr);
(gdb) bt
#0  malloc_printerr (ar_ptr=0x100101f0100101a, ptr=0x7f067955da60 &lt;generations+32&gt;, str=0x7f06785a2b8c "free(): invalid size", action=3) at malloc.c:5009
#1  _int_free (av=0x100101f0100101a, p=&lt;optimized out&gt;, have_lock=0) at malloc.c:3842
Python Exception &lt;type 'exceptions.RuntimeError'&gt; Type does not have a target.:
</code></pre>

<hr>

<p>These back traces are from Fedora 24 with Python 3.5.1 and some from Centos 7 with Python 3.4.3. So I'm ruling out issues like:</p>

<ul>
<li>bad memory (could be, but quite a coincidence that my laptop and a (virtual) server exhibit the same issue and show no otherwise work fine).</li>
<li>Issues in the OS or cPython or the combination thereof.</li>
</ul>

<p>So - as usual - it must be something in my own code. It's a mixture of threaded code for some concurrency of (computational) 'tasks' and a thread running an asyncio loop. The code base has other 'workloads' which run fine. Differences in the code which is 'serving' this 'workload' which stand out to me are that I use (threading.RLock) locks quite a bit to serialize some requests and I'm serializing and writing to disk.</p>

<p>Any suggestions on how to find a root cause would be highly appreciated!</p>

<p>Things I've tried:</p>

<ul>
<li>Stripping down the external dependencies used to the bare minimum (which was cloudpickle): no difference</li>
<li>Dumping counts of all object types as seen by the garbage collector before and after explicit collection and seeing if there were types of objects tracked just before a crash and weren't in the 'successful' garbage collections: there weren't.</li>
<li>Going through core dumps with GDB: not really consistent regarding the C nor the Python backtraces.</li>
<li>Running with MALLOC_CHECK_=2: I don't see any error messages other than that a process has exited with exit code -11.</li>
</ul>

<hr>

<h2>Edit 1</h2>

<p>Got something: <a href="https://gist.github.com/frensjan/dc9bc784229fec844403c9d9528ada66" rel="nofollow">https://gist.github.com/frensjan/dc9bc784229fec844403c9d9528ada66</a> </p>

<p>Most notably:</p>

<pre><code>==19072== Invalid write of size 8
==19072==    at 0x47A3B7: subtype_dealloc (typeobject.c:1157)
==19072==    by 0x4E0696: PyEval_EvalFrameEx (ceval.c:1388)
==19072==    by 0x58917B: gen_send_ex (genobject.c:104)
==19072==    by 0x58917B: _PyGen_Send (genobject.c:158)
...
==19072==    by 0x4E2A6A: call_function (ceval.c:4262)
==19072==    by 0x4E2A6A: PyEval_EvalFrameEx (ceval.c:2838)
==19072==  Address 0x8 is not stack'd, malloc'd or (recently) free'd
</code></pre>

<p>and</p>

<pre><code>==19072== Process terminating with default action of signal 11 (SIGSEGV): dumping core
==19072==  Access not within mapped region at address 0x8
==19072==    at 0x47A3B7: subtype_dealloc (typeobject.c:1157)
==19072==    by 0x4E0696: PyEval_EvalFrameEx (ceval.c:1388)
==19072==    by 0x58917B: gen_send_ex (genobject.c:104)
==19072==    by 0x58917B: _PyGen_Send (genobject.c:158)
</code></pre>

<p>But the errors valgrind found point to the same locations as the coredumps I got earlier, nowhere near my code ... not really sure what to do with this. </p>

<p>Environment: Python 3.4.5+ built with <code>./configure --without-pymalloc</code> on Centos 7. Ran python with <code>valgrind --tool=memcheck --dsymutil=yes --track-origins=yes --show-leak-kinds=all --trace-children=yes python ...</code></p>

<p>Any help is much appreciated!</p>

<p>I am rather confident that issue I ran across is due to <a href="https://bugs.python.org/issue26617" rel="nofollow">issue 26617</a> in CPython which is fixed in <a href="https://github.com/python/cpython/commit/7bfa6f2bfe1b14eec0e9e036866f7acd52d1c8ee" rel="nofollow">7bfa6f2</a>.</p>

<p>I've check this by reproducing the issue (running into SIGSEGV) with a build of the commit just <em>before 7bfa6f2</em> and not being able to reproduce it with a build of commit <em>7bfa6f2</em>.</p>

python c multithreading garbage-collection memory-corruption