ElementTree crash while cleaning up ParseError

[scoder]

BPO	31499
Nosy	@scoder, @vstinner, @jkloth, @serhiy-storchaka
PRs	bpo-31499, xml.etree: Fix xmlparser_gc_clear() crash #3641 [3.6] bpo-31499, xml.etree: Fix xmlparser_gc_clear() crash (GH-3641) #3645
Files	bug1.py bug2.py test_issue31499.diff

^{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 2017-09-18.13:25:23.728>
created_at = <Date 2017-09-17.17:27:08.824>
labels = ['extension-modules', '3.7', 'type-crash']
title = 'ElementTree crash while cleaning up ParseError'
updated_at = <Date 2017-09-18.13:25:23.727>
user = 'https://github.com/scoder'

bugs.python.org fields:

activity = <Date 2017-09-18.13:25:23.727>
actor = 'vstinner'
assignee = 'none'
closed = True
closed_date = <Date 2017-09-18.13:25:23.728>
closer = 'vstinner'
components = ['Extension Modules']
creation = <Date 2017-09-17.17:27:08.824>
creator = 'scoder'
dependencies = []
files = ['47144', '47145', '47146']
hgrepos = []
issue_num = 31499
keywords = ['patch']
message_count = 17.0
messages = ['302375', '302383', '302384', '302385', '302411', '302412', '302414', '302415', '302416', '302426', '302430', '302432', '302434', '302441', '302447', '302449', '302451']
nosy_count = 5.0
nosy_names = ['scoder', 'vstinner', 'jkloth', 'eli.bendersky', 'serhiy.storchaka']
pr_nums = ['3641', '3645']
priority = 'normal'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = 'crash'
url = 'https://bugs.python.org/issue31499'
versions = ['Python 3.6', 'Python 3.7']

[scoder]

I'm seeing crashes in the latest Py3.7 when I run this test (taken from lxml's compatibility test suite):

    etree = xml.etree.ElementTree

    def test_feed_parser_error_position(self):
        ParseError = etree.ParseError
        parser = XMLParser()
        try:
            parser.close()
        except ParseError:
            e = sys.exc_info()[1]
            self.assertNotEqual(None, e.code)
            self.assertNotEqual(0, e.code)
            self.assertTrue(isinstance(e.position, tuple))
            self.assertTrue(e.position >= (0, 0))

It crashes in expat/xmlparse.c, line 1464:

1459 for (;;) {
1460 BINDING *b = bindings;
1461 if (!b)
1462 break;
1463 bindings = b->nextTagBinding;
1464 FREE(b->uri); // <<<<<<<<<<<<<<< crashes here
1465 FREE(b);
1466 }
1467 }

Probably related to the new expat version (bpo-31170).

[serhiy-storchaka]

I can't reproduce a crash. Could you please provide a Python script?

[scoder]

Sorry, wrong line number. Was using an installed Py3.7, not a fresh build. However, my crashing installed version is from September 1st, *before* the expat update, which was apparently on September 5th.

With a clean debug build, I get a reproducible crash during shutdown, now with the correct line number:

Program received signal SIGSEGV, Segmentation fault.
PyExpat_XML_ParserFree (parser=0xd01a20) at .../Modules/expat/xmlparse.c:1487
1487 tagList = tagList->parent;
(gdb) p taglist
No symbol "taglist" in current context.
(gdb) list
1482 break;
1483 tagList = freeTagList;
1484 freeTagList = NULL;
1485 }
1486 p = tagList;
1487 tagList = tagList->parent;
1488 FREE(p->buf);
1489 destroyBindings(p->bindings, parser);
1490 FREE(p);
1491 }
(gdb) bt
#0 PyExpat_XML_ParserFree (parser=0xd01a20) at Modules/expat/xmlparse.c:1487
#1 0x00007fffeec83517 in xmlparser_gc_clear (self=0x7fffeeeb75d8) at Modules/_elementtree.c:3414
#2 xmlparser_dealloc (self=0x7fffeeeb75d8) at Modules/_elementtree.c:3435
#3 0x000000000041fd40 in frame_dealloc (f=0xd017c8) at Objects/frameobject.c:428
#4 0x000000000044f5e5 in tb_dealloc (tb=0x7ffff632d218) at Python/traceback.c:56
#5 0x000000000049c59d in BaseException_clear (self=0x7ffff6567dd8) at Objects/exceptions.c:78
#6 SyntaxError_clear (self=0x7ffff6567dd8) at Objects/exceptions.c:1381
#7 0x0000000000458104 in delete_garbage (old=<optimized out>, collectable=<optimized out>) at Modules/gcmodule.c:759
#8 collect (generation=generation@entry=2, n_collected=n_collected@entry=0x7fffffffd6c8, n_uncollectable=n_uncollectable@entry=0x7fffffffd6d0, nofail=nofail@entry=0) at Modules/gcmodule.c:911
#9 0x0000000000458d2b in collect_with_callback (generation=2) at Modules/gcmodule.c:1020
#10 PyGC_Collect () at Modules/gcmodule.c:1507
#11 0x0000000000439aaf in Py_FinalizeEx () at Python/pylifecycle.c:1002
#12 0x000000000043b3d8 in Py_Exit (sts=sts@entry=0) at Python/pylifecycle.c:1953
#13 0x000000000043f4e8 in handle_system_exit () at Python/pythonrun.c:608
#14 0x000000000043f94d in handle_system_exit () at Python/pythonrun.c:635
#15 PyErr_PrintEx (set_sys_last_vars=set_sys_last_vars@entry=1) at Python/pythonrun.c:618
#16 0x000000000043fc4a in PyErr_Print () at Python/pythonrun.c:514
#17 0x0000000000441475 in PyRun_SimpleFileExFlags (fp=fp@entry=0x9dc050, filename=<optimized out>, closeit=closeit@entry=1, flags=flags@entry=0x7fffffffd8e0) at Python/pythonrun.c:407
#18 0x0000000000441633 in PyRun_AnyFileExFlags (fp=fp@entry=0x9dc050, filename=<optimized out>, closeit=closeit@entry=1, flags=flags@entry=0x7fffffffd8e0) at Python/pythonrun.c:83
#19 0x000000000045666c in run_file (p_cf=0x7fffffffd8e0, filename=0x9973d0 L"test.py", fp=0x9dc050) at Modules/main.c:341
#20 Py_Main (argc=argc@entry=6, argv=argv@entry=0x996020) at Modules/main.c:895
#21 0x000000000041fa2b in main (argc=6, argv=<optimized out>) at ./Programs/python.c:102

I get it in lxml's test suite runs, will try to reduce it to a test script.

[scoder]

Minimal reproducer seems to be this:
----------

import xml.etree.ElementTree as etree

def test():
    parser = etree.XMLParser()
    try:
        parser.close()
    except etree.ParseError as exc:
        e = exc  # must keep local reference!

test()

---

The master gitrev I tested is 132a7d7

Since this happens during GC and finalisation, it's quite possible that it's not a bug in ET per se. It might just be a prematurely cleared reference in some tp_clear(), or something like that. (Changing ticket title appropriately.)

[vstinner]

I confirm the crash using attached bug1.py (first example, completed) and bug2.py (second example).

[scoder]

Thanks for confirming, Victor.
I hadn't realised that the first update of expat was already back in June. That means it's not ruled out yet as a source of this crash. Bisecting is probably a good idea.

[vstinner]

The bug is at this line:

Breakpoint 6, xmlparser_gc_clear (self=0x7ffff7e28c08) at /home/haypo/prog/python/master/Modules/_elementtree.c:3414

static int
xmlparser_gc_clear(XMLParserObject *self)
{
    EXPAT(ParserFree)(self->parser);   // <--- HERE
    ...
}

This function calls XML_ParserFree() twice on the same parser object. The first call is fine and frees the memory. Since we now use Python memory allocators, XML_ParserFree() fills the freed memory with 0xDB byte pattern (when Python is in debug mode).

The second XML_ParserFree() call uses freed memory (filled with 0xDB in debug mode).

Call 1: a GC collection

Breakpoint 6, xmlparser_gc_clear (self=0x7ffff7e28c08) at /home/haypo/prog/python/master/Modules/_elementtree.c:3414
(gdb) up
#1 0x0000000000446636 in delete_garbage (collectable=0x7fffffffd9a0, old=0x9b8f90 <_PyRuntime+432>) at Modules/gcmodule.c:759
(gdb) up
#2 0x0000000000446ade in collect (generation=2, n_collected=0x7fffffffda30, n_uncollectable=0x7fffffffda28, nofail=0) at Modules/gcmodule.c:911
(gdb) cont
Continuing.

Call 2: xmlparser_dealloc()

Breakpoint 6, xmlparser_gc_clear (self=0x7ffff7e28c08) at /home/haypo/prog/python/master/Modules/_elementtree.c:3414
(gdb) up
#1 0x00007ffff0038cb8 in xmlparser_dealloc (self=0x7ffff7e28c08) at /home/haypo/prog/python/master/Modules/_elementtree.c:3435

IMHO it's an obvious bug in Python. The question is more why/how the code didn't crash before? :-)

[vstinner]

Python 2.7 is not affected because it doesn't implement tp_clear (it doesn't have xmlparser_gc_clear()), only xmlparser_dealloc() calls EXPAT(ParserFree)(self->parser).

I'm unable to reproduce the bug in Python 3.5 nor 3.6.

bug2.py creates a reference cycle the "except etree.ParseError as exc: e = exc # must keep local reference!" which requires to trigger a garbage collection to clear the "parser" variable.

[scoder]

The question is more why/how the code didn't crash before? :-)

Typical case of a Schroedinbug.

[vstinner]

> The question is more why/how the code didn't crash before? :-)

Typical case of a Schroedinbug.

I don't believe in the chaos :-)

I ran a "git bisect" since January 1st, 2017. Attached bug2.py started to crash since the following commit related to bpo-29049.
---
5a625d0 is the first bad commit
commit 5a625d0
Author: INADA Naoki <songofacandy@gmail.com>
Date: Sat Dec 24 20:19:08 2016 +0900

Issue bpo-29049: Call _PyObject_GC_TRACK() lazily when calling Python function.

Calling function is up to 5% faster.

---

This change is also correct. It's more that the change showed a bug which was hidden before.

It's just that now the garbage collector breaks the reference cycle differently since frames tracked differently by the GC.

[vstinner]

Attached PR 3641 fixes bug1.py and bug2.py crashes.

Sadly, I failed to write a reliable unit test using bug2.py. The bug requires to trigger the garbage collector in a specific order which depends on how frames are tracked by the GC...