Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

traceback.clear_frames(): Objects/typeobject.c:3086: _PyType_Lookup: Assertion `!PyErr_Occurred()' failed. #78249

Closed
serhiy-storchaka opened this issue Jul 8, 2018 · 13 comments
Labels
3.7 (EOL) end of life 3.8 only security fixes interpreter-core (Objects, Python, Grammar, and Parser dirs) type-crash A hard crash of the interpreter, possibly with a core dump

Comments

@serhiy-storchaka
Copy link
Member

BPO 34068
Nosy @scoder, @vstinner, @nedbat, @serhiy-storchaka, @ZackerySpytz, @miss-islington
PRs
  • bpo-34068: _io__IOBase_close_impl could call _PyObject_SetAttrId with an exception set #8282
  • [3.7] bpo-34068: _io__IOBase_close_impl could call _PyObject_SetAttrId with an exception set (GH-8282) #8310
  • [3.6] bpo-34068: _io__IOBase_close_impl could call _PyObject_SetAttrId with an exception set (GH-8282). #8312
  • [2.7] bpo-34068: iobase_close could call PyObject_SetAttrString with an exception set (GH-8282). (GH-8312) #8314
  • 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 2018-09-10.16:10:14.697>
    created_at = <Date 2018-07-08.06:34:42.085>
    labels = ['interpreter-core', '3.7', '3.8', 'type-crash']
    title = "traceback.clear_frames(): Objects/typeobject.c:3086: _PyType_Lookup: Assertion `!PyErr_Occurred()' failed."
    updated_at = <Date 2018-09-10.16:10:14.696>
    user = 'https://github.com/serhiy-storchaka'

    bugs.python.org fields:

    activity = <Date 2018-09-10.16:10:14.696>
    actor = 'benjamin.peterson'
    assignee = 'none'
    closed = True
    closed_date = <Date 2018-09-10.16:10:14.697>
    closer = 'benjamin.peterson'
    components = ['Interpreter Core']
    creation = <Date 2018-07-08.06:34:42.085>
    creator = 'serhiy.storchaka'
    dependencies = []
    files = []
    hgrepos = []
    issue_num = 34068
    keywords = ['patch']
    message_count = 13.0
    messages = ['321261', '321262', '321471', '321473', '321474', '321481', '321795', '321798', '321801', '321813', '321816', '321818', '321839']
    nosy_count = 6.0
    nosy_names = ['scoder', 'vstinner', 'nedbat', 'serhiy.storchaka', 'ZackerySpytz', 'miss-islington']
    pr_nums = ['8282', '8310', '8312', '8314']
    priority = 'normal'
    resolution = 'fixed'
    stage = 'resolved'
    status = 'closed'
    superseder = None
    type = 'crash'
    url = 'https://bugs.python.org/issue34068'
    versions = ['Python 3.6', 'Python 3.7', 'Python 3.8']

    @serhiy-storchaka
    Copy link
    Member Author

    I got the following failure when running tests with coverage on VSTS.

    https://python.visualstudio.com/cpython/cpython%20Team/_build/results?buildId=14680&view=logs

    2018-07-05T12:11:22.0719913Z 0:17:49 load avg: 0.82 [373/413] test_urllib
    2018-07-05T12:11:22.2574704Z python: Objects/typeobject.c:3086: _PyType_Lookup: Assertion `!PyErr_Occurred()' failed.
    2018-07-05T12:11:22.2603179Z Fatal Python error: Aborted
    2018-07-05T12:11:22.2608453Z
    2018-07-05T12:11:22.2622441Z Current thread 0x00007fb6465c7700 (most recent call first):
    2018-07-05T12:11:22.2634973Z File "/opt/vsts/work/1/s/Lib/http/client.py", line 405 in close
    2018-07-05T12:11:22.2650517Z File "/opt/vsts/work/1/s/Lib/traceback.py", line 216 in clear_frames
    2018-07-05T12:11:22.2663944Z File "/opt/vsts/work/1/s/Lib/unittest/case.py", line 205 in __exit__
    2018-07-05T12:11:22.2676467Z File "/opt/vsts/work/1/s/Lib/test/test_urllib.py", line 368 in test_invalid_redirect
    2018-07-05T12:11:22.2704792Z File "/opt/vsts/work/1/s/Lib/unittest/case.py", line 615 in run
    2018-07-05T12:11:22.2727078Z File "/opt/vsts/work/1/s/Lib/unittest/case.py", line 663 in __call__
    2018-07-05T12:11:22.2738921Z File "/opt/vsts/work/1/s/Lib/unittest/suite.py", line 122 in run
    2018-07-05T12:11:22.2754215Z File "/opt/vsts/work/1/s/Lib/unittest/suite.py", line 84 in __call__
    2018-07-05T12:11:22.2768065Z File "/opt/vsts/work/1/s/Lib/unittest/suite.py", line 122 in run
    2018-07-05T12:11:22.2784999Z File "/opt/vsts/work/1/s/Lib/unittest/suite.py", line 84 in __call__
    2018-07-05T12:11:22.2797611Z File "/opt/vsts/work/1/s/Lib/unittest/suite.py", line 122 in run
    2018-07-05T12:11:22.2813174Z File "/opt/vsts/work/1/s/Lib/unittest/suite.py", line 84 in __call__
    2018-07-05T12:11:22.2826999Z File "/opt/vsts/work/1/s/Lib/test/support/init.py", line 1782 in run
    2018-07-05T12:11:22.2841544Z File "/opt/vsts/work/1/s/Lib/test/support/init.py", line 1883 in _run_suite
    2018-07-05T12:11:22.2854173Z File "/opt/vsts/work/1/s/Lib/test/support/init.py", line 1973 in run_unittest
    2018-07-05T12:11:22.2868193Z File "/opt/vsts/work/1/s/Lib/test/libregrtest/runtest.py", line 175 in test_runner
    2018-07-05T12:11:22.2883280Z File "/opt/vsts/work/1/s/Lib/test/libregrtest/runtest.py", line 179 in runtest_inner
    2018-07-05T12:11:22.2898238Z File "/opt/vsts/work/1/s/Lib/test/libregrtest/runtest.py", line 140 in runtest
    2018-07-05T12:11:22.2912684Z File "/opt/vsts/work/1/s/Lib/test/libregrtest/main.py", line 384 in run_tests_sequential
    2018-07-05T12:11:22.2927233Z File "/opt/vsts/work/1/s/Lib/test/libregrtest/main.py", line 488 in run_tests
    2018-07-05T12:11:22.2941508Z File "/opt/vsts/work/1/s/Lib/test/libregrtest/main.py", line 566 in _main
    2018-07-05T12:11:22.2955879Z File "/opt/vsts/work/1/s/Lib/test/libregrtest/main.py", line 531 in main
    2018-07-05T12:11:22.2971440Z File "/opt/vsts/work/1/s/Lib/test/libregrtest/main.py", line 584 in main
    2018-07-05T12:11:22.2985417Z File "/opt/vsts/work/1/s/Lib/test/main.py", line 2 in <module>
    2018-07-05T12:11:22.3002269Z File "/opt/vsts/work/1/s/venv/lib/python3.8/site-packages/coverage/execfile.py", line 184 in run_python_file
    2018-07-05T12:11:22.3017503Z File "/opt/vsts/work/1/s/venv/lib/python3.8/site-packages/coverage/execfile.py", line 114 in run_python_module
    2018-07-05T12:11:22.3035688Z File "/opt/vsts/work/1/s/venv/lib/python3.8/site-packages/coverage/cmdline.py", line 624 in do_run
    2018-07-05T12:11:22.3051283Z File "/opt/vsts/work/1/s/venv/lib/python3.8/site-packages/coverage/cmdline.py", line 488 in command_line
    2018-07-05T12:11:22.3067258Z File "/opt/vsts/work/1/s/venv/lib/python3.8/site-packages/coverage/cmdline.py", line 753 in main
    2018-07-05T12:11:22.3083839Z File "/opt/vsts/work/1/s/venv/lib/python3.8/site-packages/coverage/main.py", line 8 in <module>
    2018-07-05T12:11:22.3099563Z File "/opt/vsts/work/1/s/Lib/runpy.py", line 85 in _run_code
    2018-07-05T12:11:22.3113337Z File "/opt/vsts/work/1/s/Lib/runpy.py", line 193 in _run_module_as_main
    2018-07-05T12:11:22.4058762Z Aborted (core dumped)
    2018-07-05T12:11:22.4252037Z ##[error]Bash exited with code '134'.
    2018-07-05T12:11:22.5073689Z ##[section]Finishing: Tests with coverage

    It is not related to changes made in PR 8071.

    Is Coverage.py doing something wrong or just exposes a flaw in the interpreter?

    @serhiy-storchaka serhiy-storchaka added 3.8 only security fixes interpreter-core (Objects, Python, Grammar, and Parser dirs) type-crash A hard crash of the interpreter, possibly with a core dump labels Jul 8, 2018
    @scoder
    Copy link
    Contributor

    scoder commented Jul 8, 2018

    I added this assertion exactly for the purpose of finding this kind of bug. It means that some code tried to look up an attribute with a live exception set, which previously could swallow the exception in certain situations, and even if not, it is always the wrong thing to do.

    Looking at the stack trace, my guess is that the problem is closer to the crash than the coverage calls. I'd suggest taking a look at the frame cleanup in the traceback module.

    @vstinner vstinner changed the title Assertion failure in _PyType_Lookup traceback.clear_frames(): Objects/typeobject.c:3086: _PyType_Lookup: Assertion `!PyErr_Occurred()' failed. Jul 11, 2018
    @vstinner
    Copy link
    Member

    I'm able to reproduce the bug on my Fedora using:

    vstinner@apu$ gdb -args ENV/bin/python -m coverage run --pylib -m test --fail-env-changed -uall,-cpu test_urllib -F
    (gdb) run

    python: Objects/typeobject.c:3086: _PyType_Lookup: Assertion `!PyErr_Occurred()' failed.

    Program received signal SIGABRT, Aborted.
    0x00007ffff7093f2b in raise () from /lib64/libc.so.6

    (gdb) py-bt
    Traceback (most recent call first):
      <built-in method close of HTTPResponse object at remote 0x7fffe581ff50>
      File "/home/vstinner/prog/python/master/Lib/http/client.py", line 405, in close
        super().close() # set "closed" flag
      File "/home/vstinner/prog/python/master/Lib/traceback.py", line 216, in clear_frames
        tb.tb_frame.clear()
      File "/home/vstinner/prog/python/master/Lib/unittest/case.py", line 205, in __exit__
        traceback.clear_frames(tb)
      File "/home/vstinner/prog/python/master/Lib/unittest/case.py", line 178, in handle
        callable_obj(*args, **kwargs)
      File "/home/vstinner/prog/python/master/Lib/unittest/case.py", line 743, in assertRaises
        return context.handle('assertRaises', args, kwargs)
      File "/home/vstinner/prog/python/master/Lib/test/test_urllib.py", line 382, in test_redirect_limit_independent
        "http://something")
      (...)

    (gdb) where
    #0 0x00007ffff7093f2b in raise () from /lib64/libc.so.6
    #1 0x00007ffff707e561 in abort () from /lib64/libc.so.6
    #2 0x00007ffff707e431 in __assert_fail_base.cold.0 () from /lib64/libc.so.6
    #3 0x00007ffff708c692 in __assert_fail () from /lib64/libc.so.6
    #4 0x00000000004aa2ea in _PyType_Lookup (type=0xdc1b30, name='__IOBase_closed') at Objects/typeobject.c:3086
    #5 0x00000000004883ff in _PyObject_GenericSetAttrWithDict (
    obj=<HTTPResponse(fp=<FakeSocket(io_refs=0) at remote 0x7fffe4e2f1d0>, debuglevel=0, _method='GET', headers=<HTTPMessage(policy=<Compat32 at remote 0x7fffe553efb0>, _headers=[('Location', 'file://guidocomputer.athome.com:/python/license'), ('Connection', 'close')], _unixfrom=None, _payload='', _charset=None, preamble=None, epilogue=None, defects=[], _default_type='text/plain') at remote 0x7fffe542f4d0>, msg=<...>, version=11, status=302, reason='Found', chunked=False, chunk_left='UNKNOWN', length=None, will_close=True, code=302, _finalizing=True) at remote 0x7fffe581ff50>, name='__IOBase_closed', value=True, dict=0x0) at Objects/object.c:1292
    #6 0x000000000048871a in PyObject_GenericSetAttr (
    obj=<HTTPResponse(fp=<FakeSocket(io_refs=0) at remote 0x7fffe4e2f1d0>, debuglevel=0, _method='GET', headers=<HTTPMessage(policy=<Compat32 at remote 0x7fffe553efb0>, _headers=[('Location', 'file://guidocomputer.athome.com:/python/license'), ('Connection', 'close')], _unixfrom=None, _payload='', _charset=None, preamble=None, epilogue=None, defects=[], _default_type='text/plain') at remote 0x7fffe542f4d0>, msg=<...>, version=11, status=302, reason='Found', chunked=False, chunk_left='UNKNOWN', length=None, will_close=True, code=302, _finalizing=True) at remote 0x7fffe581ff50>, name='__IOBase_closed', value=True) at Objects/object.c:1340
    #7 0x00000000004873a0 in PyObject_SetAttr (
    v=<HTTPResponse(fp=<FakeSocket(io_refs=0) at remote 0x7fffe4e2f1d0>, debuglevel=0, _method='GET', headers=<HTTPMessage(policy=<Compat32 at remote 0x7fffe553efb0>, _headers=[('Location', 'file://guidocomputer.athome.com:/python/license'), ('Connection', 'close')], _unixfrom=None, _payload='', _charset=None, preamble=None, epilogue=None, defects=[], _default_type='text/plain') at remote 0x7fffe542f4d0>, msg=<...>, version=11, status=302, reason='Found', chunked=False, chunk_left='UNKNOWN', length=None, will_close=True, code=302, _finalizing=True) at remote 0x7fffe581ff50>, name='__IOBase_closed', value=True) at Objects/object.c:977
    #8 0x0000000000486f03 in _PyObject_SetAttrId (
    v=<HTTPResponse(fp=<FakeSocket(io_refs=0) at remote 0x7fffe4e2f1d0>, debuglevel=0, _method='GET', headers=<HTTPMessage(policy=<Compat32 at remote 0x7fffe553efb0>, _headers=[('Location', 'file://guidocomputer.athome.com:/python/license'), ('Connection', 'close')], _unixfrom=None, _payload='', _charset=None, preamble=None, epilogue=None, defects=[], _default_type='text/plain') at remote 0x7fffe542f4d0>, msg=<...>, version=11, status=302, reason='Found', chunked=False, chunk_left='UNKNOWN', length=None, will_close=True, code=302, _finalizing=True) at remote 0x7fffe581ff50>, name=0x9d4330 <PyId___IOBase_closed>, w=True) at Objects/object.c:857
    #9 0x0000000000625d9c in _io__IOBase_close_impl (
    self=<HTTPResponse(fp=<FakeSocket(io_refs=0) at remote 0x7fffe4e2f1d0>, debuglevel=0, _method='GET', headers=<HTTPMessage(policy=<Compat32 at remote 0x7fffe553efb0>, _headers=[('Location', 'file://guidocomputer.athome.com:/python/license'), ('Connection', 'close')], _unixfrom=None, _payload='', _charset=None, preamble=None, epilogue=None, defects=[], _default_type='text/plain') at remote 0x7fffe542f4d0>, msg=<...>, version=11, status=302, reason='Found', chunked=False, chunk_left='UNKNOWN', length=None, will_close=True, code=302, _finalizing=---T---Type ---Type <return>---Type <ret---Type <ret---Type ---Type ---Type <return>---Type <ret---Type <return> to ---Type <return>---Type ---T---Type <return>---Type ---T---Type <return> to continue, or q <return> to quit---
    ) at remote 0x7fffe581ff50>) at ./Modules/_io/iobase.c:239
    #10 0x0000000000627e12 in _io__IOBase_close (
    self=<HTTPResponse(fp=<FakeSocket(io_refs=0) at remote 0x7fffe4e2f1d0>, debuglevel=0, _method='GET', headers=<HTTPMessage(policy=<Compat32 at remote 0x7fffe553efb0>, _headers=[('Location', 'file://guidocomputer.athome.com:/python/license'), ('Connection', 'close')], _unixfrom=None, _payload='', _charset=None, preamble=None, epilogue=None, defects=[], _default_type='text/plain') at remote 0x7fffe542f4d0>, msg=<...>, version=11, status=302, reason='Found', chunked=False, chunk_left='UNKNOWN', length=None, will_close=True, code=302, _finalizing=True) at remote 0x7fffe581ff50>, _unused_ignored=0x0) at ./Modules/_io/clinic/iobase.c.h:60
    #11 0x0000000000438cb3 in _PyMethodDef_RawFastCallKeywords (method=0x9d4d40 <iobase_methods+128>,
    self=<HTTPResponse(fp=<FakeSocket(io_refs=0) at remote 0x7fffe4e2f1d0>, debuglevel=0, _method='GET', headers=<HTTPMessage(policy=<Compat32 at remote 0x7fffe553efb0>, _headers=[('Location', 'file://guidocomputer.athome.com:/python/license'), ('Connection', 'close')], _unixfrom=None, _payload='', _charset=None, preamble=None, epilogue=None, defects=[], _default_type='text/plain') at remote 0x7fffe542f4d0>, msg=<...>, version=11, status=302, reason='Found', chunked=False, chunk_left='UNKNOWN', length=None, will_close=True, code=302, _finalizing=True) at remote 0x7fffe581ff50>, args=0x7fffe4e793e8, nargs=0, kwnames=0x0) at Objects/call.c:629
    #12 0x000000000043910d in _PyCFunction_FastCallKeywords (func=<built-in method close of HTTPResponse object at remote 0x7fffe581ff50>, args=0x7fffe4e793e8, nargs=0, kwnames=0x0)
    at Objects/call.c:730
    #13 0x00000000005500e9 in call_function (pp_stack=0x7ffffffb7da0, oparg=0, kwnames=0x0) at Python/ceval.c:4565
    #14 0x0000000000548e1d in _PyEval_EvalFrameDefault (
    f=Frame 0x7fffe4e79250, for file /home/vstinner/prog/python/master/Lib/http/client.py, line 405, in close (self=<HTTPResponse(fp=<FakeSocket(io_refs=0) at remote 0x7fffe4e2f1d0>, debuglevel=0, _method='GET', headers=<HTTPMessage(policy=<Compat32 at remote 0x7fffe553efb0>, _headers=[('Location', 'file://guidocomputer.athome.com:/python/license'), ('Connection', 'close')], _unixfrom=None, _payload='', _charset=None, preamble=None, epilogue=None, defects=[], _default_type='text/plain') at remote 0x7fffe542f4d0>, msg=<...>, version=11, status=302, reason='Found', chunked=False, chunk_left='UNKNOWN', length=None, will_close=True, code=302, _finalizing=True) at remote 0x7fffe581ff50>), throwflag=0)
    at Python/ceval.c:3159
    (...)

    The bug is in _io__IOBase_close_impl(). I modified the code:

    assert(!PyErr_Occurred());
    
        res = PyObject_CallMethodObjArgs(self, _PyIO_str_flush, NULL);
    assert(!PyErr_Occurred());     /* <---- THIS ASSERTION FAILS */
    
        if (_PyObject_SetAttrId(self, &PyId___IOBase_closed, Py_True) < 0) {
            Py_XDECREF(res);
            return NULL;
        }

    The problem is that _PyObject_SetAttrId() is called while the flush() method raised an exception.

    We need something like PyErr_Fetch/PyErr_Store to set the attribute.

    @vstinner
    Copy link
    Member

    Stefan Behnel: "I added this assertion exactly for the purpose of finding this kind of bug. It means that some code tried to look up an attribute with a live exception set, which previously could swallow the exception in certain situations, and even if not, it is always the wrong thing to do."

    The assertion failure is a little bit "far" from the bug: would it make sense to add "assert(!PyErr_Occurred());" to the entry point of:

    • PyObject_HasAttr()
    • PyObject_SetAttr()
    • PyObject_SetAttrString()
    • _PyObject_SetAttrId()
    • type_getattro()
    • slot_tp_getattr_hook()
    • and other similar functions?

    A few years ago, I added "assert(!PyErr_Occurred());" to the entry point of C functions which can call arbitrary code like _PyEval_EvalFrameDefault(), PyObject_Call(), etc. It helped to find many bugs.

    @vstinner
    Copy link
    Member

    res = PyObject_CallMethodObjArgs(self, _PyIO_str_flush, NULL);
    assert(!PyErr_Occurred()); /* <---- THIS ASSERTION FAILS */

    Using this additional assertion, test_io also fails on test_flush_error_on_close().

    @serhiy-storchaka
    Copy link
    Member Author

    _PyType_Lookup doesn't set an exception. But if an exception was raised inside, it will be cleared, and this will clear an exception if it was raised before _PyType_Lookup. assert() is needed for guaranteeing that no exception will be lost.

    I'm +1 for saving/restoring (or rather chaining) the exception.

    @ZackerySpytz ZackerySpytz mannequin added the 3.7 (EOL) end of life label Jul 14, 2018
    @serhiy-storchaka
    Copy link
    Member Author

    New changeset 28f0736 by Serhiy Storchaka (Zackery Spytz) in branch 'master':
    bpo-34068: _io__IOBase_close_impl could call _PyObject_SetAttrId with an exception set (GH-8282)
    28f0736

    @miss-islington
    Copy link
    Contributor

    New changeset 6020d98 by Miss Islington (bot) in branch '3.7':
    bpo-34068: _io__IOBase_close_impl could call _PyObject_SetAttrId with an exception set (GH-8282)
    6020d98

    @serhiy-storchaka
    Copy link
    Member Author

    New changeset cc13016 by Serhiy Storchaka in branch '3.6':
    bpo-34068: _io__IOBase_close_impl could call _PyObject_SetAttrId with an exception set (GH-8282). (GH-8312)
    cc13016

    @vstinner
    Copy link
    Member

    The assertion failure is a little bit "far" from the bug: would it make sense to add "assert(!PyErr_Occurred());" to the entry point of:

    Stefan, Serhiy: any opinion on my idea?

    For example, PyObject_HasAttr() can replace and clear the current exception *by design*. This function does more or less:

    try: obj.attr; return True
    except AttributeError: return False

    int
    PyObject_HasAttr(PyObject *v, PyObject *name)
    {
        PyObject *res;
        if (_PyObject_LookupAttr(v, name, &res) < 0) {
            PyErr_Clear();
            return 0;
        }
        if (res == NULL) {
            return 0;
        }
        Py_DECREF(res);
        return 1;
    }

    @vstinner
    Copy link
    Member

    Python 2.7 also has the io module: it may be good to backport the change to Python 2.7 as well, no? I see the same bug in 2.7:

        res = PyObject_CallMethodObjArgs(self, _PyIO_str_flush, NULL);
        PyObject_SetAttrString(self, "__IOBase_closed", Py_True);
        if (res == NULL) {
            return NULL;
        }

    @vstinner vstinner reopened this Jul 17, 2018
    @serhiy-storchaka
    Copy link
    Member Author

    The assertion failure is a little bit "far" from the bug: would it make sense to add "assert(!PyErr_Occurred());" to the entry point of:

    This looks like a part of larger issue, and I think it deserves a separate issue on the tracker.

    See also bpo-26776.

    @serhiy-storchaka
    Copy link
    Member Author

    New changeset fc153d1 by Serhiy Storchaka in branch '2.7':
    [2.7] bpo-34068: iobase_close could call PyObject_SetAttrString with an exception set (GH-8282). (GH-8312) (GH-8314)
    fc153d1

    @ezio-melotti ezio-melotti transferred this issue from another repository Apr 10, 2022
    Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
    Labels
    3.7 (EOL) end of life 3.8 only security fixes interpreter-core (Objects, Python, Grammar, and Parser dirs) type-crash A hard crash of the interpreter, possibly with a core dump
    Projects
    None yet
    Development

    No branches or pull requests

    5 participants