update_refs: Assertion `_PyGCHead_REFS(gc) != 0' failed when running test_logging_undefined() of tests/test_api.py

[vstinner]

Hi,

Python does crash when running Jinja2 test suite on a Python compiled in debug mode and Jinja2 version 2.10.1:

vstinner@apu$ /home/vstinner/myprojects/python-ci/work/jinja/venv/bin/python -bb -X dev -Werror::BytesWarning -m pytest --tb=short -s Jinja2-2.10.1/tests/test_api.py -k test_logging_undefined -v
=============================================================================================== test session starts ===============================================================================================
platform linux -- Python 3.7.4+, pytest-5.0.1, py-1.8.0, pluggy-0.12.0 -- /home/vstinner/myprojects/python-ci/work/jinja/venv/bin/python
cachedir: .pytest_cache
rootdir: /home/vstinner/myprojects/python-ci/work/jinja/Jinja2-2.10.1, inifile: setup.cfg
collected 6 items / 5 deselected / 1 selected                                                                                                                                                                     

Jinja2-2.10.1/tests/test_api.py::TestUndefined::test_logging_undefined PASSED

================================================================================================ warnings summary =================================================================================================
venv/lib/python3.7/site-packages/_pytest/mark/structures.py:332
  /home/vstinner/myprojects/python-ci/work/jinja/venv/lib/python3.7/site-packages/_pytest/mark/structures.py:332: PytestUnknownMarkWarning: Unknown pytest.mark.api - is this a typo?  You can register custom marks to avoid this warning - for details, see https://docs.pytest.org/en/latest/mark.html
    PytestUnknownMarkWarning,

venv/lib/python3.7/site-packages/_pytest/mark/structures.py:332
  /home/vstinner/myprojects/python-ci/work/jinja/venv/lib/python3.7/site-packages/_pytest/mark/structures.py:332: PytestUnknownMarkWarning: Unknown pytest.mark.undefined - is this a typo?  You can register custom marks to avoid this warning - for details, see https://docs.pytest.org/en/latest/mark.html
    PytestUnknownMarkWarning,

-- Docs: https://docs.pytest.org/en/latest/warnings.html
=============================================================================== 1 passed, 5 deselected, 2 warnings in 0.05 seconds ================================================================================
python: Modules/gcmodule.c:262: update_refs: Assertion `_PyGCHead_REFS(gc) != 0' failed.
Aborted (core dumped)

vstinner@apu$ echo $?
134

I get the same crash on Python 3.7, 3.8 and master branch (future 3.9).

According to gdb, the invalid object is a traceback object:

(gdb) up
#4  0x00000000005c4638 in update_refs (containers=0x8197e0 <_PyRuntime+448>) at Modules/gcmodule.c:262
262	        assert(_PyGCHead_REFS(gc) != 0);

(gdb) p *gc
$1 = {
  gc = {
    gc_next = 0xc92da0, 
    gc_prev = 0xc95760, 
    gc_refs = 0
  }, 
  dummy = <invalid float value>
}

$3 = (PyTracebackObject *) 0x7fffe91fe360
(gdb) p *(PyTracebackObject*)(gc[1])
$4 = {
  ob_base = {
    _ob_next = 0x7fffe924fd60, 
    _ob_prev = 0x7fffe91fe3e0, 
    ob_refcnt = 3, 
    ob_type = 0x7bb740 <PyTraceBack_Type>
  }, 
  tb_next = 0x7fffe91fe2e0, 
  tb_frame = 0xc97d00, 
  tb_lasti = 56, 
  tb_lineno = 727
}

pip freeze:

atomicwrites==1.3.0
attrs==19.1.0
importlib-metadata==0.19
Jinja2==2.10.1
MarkupSafe==1.1.1
more-itertools==7.2.0
packaging==19.1
pluggy==0.12.0
py==1.8.0
pyparsing==2.4.2
pytest==5.0.1
six==1.12.0
wcwidth==0.1.7
zipp==0.5.2

---

First, I reported the bug to pytest: pytest-dev/pytest#5766

But I managed to write a reproducer which doesn't use pytest nor jinja2, by copying jinja2 into my reproducer script. My reproducer only has 4 imports:

import sys
import textwrap
import ctypes
from types import TracebackType

I'm now pretty sure that the bug is around "def _init_ugly_crap():" which uses ctypes. The code seems to be written for CPython in release mode.

I'm not sure how to attach a .py file to a GitHub issue, so I uploaded it at: http://haypo.alwaysdata.net/tmp/jinja_test_api.py

[vstinner]

I wrote #1051 to fix this crash.

[vstinner]

Maybe the root issue is around this code of tb_set_next():

            old = _Traceback.from_address(id(tb.tb_next))
            old.ob_refcnt -= 1

I'm not a ctypes expert. Another attempt to fix the bug:

diff --git a/jinja2/debug.py b/jinja2/debug.py
index b61139f..e31b8a0 100644
--- a/jinja2/debug.py
+++ b/jinja2/debug.py
@@ -349,14 +349,17 @@ def _init_ugly_crap():
             raise TypeError('tb_set_next arguments must be traceback objects')
         obj = _Traceback.from_address(id(tb))
         if tb.tb_next is not None:
-            old = _Traceback.from_address(id(tb.tb_next))
-            old.ob_refcnt -= 1
+            old = tb.tb_next.contents
+        else:
+            old = None
         if next is None:
             obj.tb_next = ctypes.POINTER(_Traceback)()
         else:
             next = _Traceback.from_address(id(next))
             next.ob_refcnt += 1
             obj.tb_next = ctypes.pointer(next)
+        if old is not None:
+            old.ob_refcnt -= 1
 
     return tb_set_next

I'm not sure about next = _Traceback.from_address(id(next)) neither.

But using my PR #1051 is better, Python implements sanity checks. For example, Python detects cycles.