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.

Sign up for GitHub

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

Jump to bottom

Weird test failures related to tracebacks #95818

Closed
Themanwithoutaplan opened this issue Aug 9, 2022 · 50 comments
Closed

Weird test failures related to tracebacks #95818

Themanwithoutaplan opened this issue Aug 9, 2022 · 50 comments
Assignees
@markshannon @brandtbucher
Labels
3.11 only security fixes 3.12 bugs and security fixes release-blocker type-bug An unexpected behavior, bug, or error type-crash A hard crash of the interpreter, possibly with a core dump

Comments

@Themanwithoutaplan
Copy link

Bug report

I've recently been getting test failures, including segmentation faults, on different arcs (MacOS, Docker images) with Python 3.11 beta. The test itself is not at fault so I guess it's some kind of runtime issue.

Here's the traceback:

________________________ test_read_single_cell_formula[False-='Sheet2 - Numbers'!D5] ________________________

exc = <class 'ResourceWarning'>
value = ResourceWarning("unclosed file <_io.BufferedReader name='sample.xlsx'>")
tb = <traceback object at 0x10e3f4b00>, limit = None, chain = True

    def format_exception(exc, /, value=_sentinel, tb=_sentinel, limit=None, \
                         chain=True):
        """Format a stack trace and the exception information.

        The arguments have the same meaning as the corresponding arguments
        to print_exception().  The return value is a list of strings, each
        ending in a newline and some containing internal newlines.  When
        these lines are concatenated and printed, exactly the same text is
        printed as does print_exception().
        """
        value, tb = _parse_value_tb(exc, value, tb)
>       te = TracebackException(type(value), value, tb, limit=limit, compact=True)

chain      = True
exc        = <class 'ResourceWarning'>
limit      = None
tb         = <traceback object at 0x10e3f4b00>
value      = ResourceWarning("unclosed file <_io.BufferedReader name='sample.xlsx'>")

/opt/local/Library/Frameworks/Python.framework/Versions/3.11/lib/python3.11/traceback.py:139:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
/opt/local/Library/Frameworks/Python.framework/Versions/3.11/lib/python3.11/traceback.py:688: in __init__
    self.stack = StackSummary._extract_from_extended_frame_gen(
        _seen      = {4539126048}
        capture_locals = False
        compact    = True
        exc_traceback = <traceback object at 0x10e3f4b00>
        exc_type   = <class 'ResourceWarning'>
        exc_value  = ResourceWarning("unclosed file <_io.BufferedReader name='sample.xlsx'>")
        is_recursive_call = False
        limit      = None
        lookup_lines = True
        max_group_depth = 10
        max_group_width = 15
        self       = <traceback.TracebackException object at 0x10e4029d0>
/opt/local/Library/Frameworks/Python.framework/Versions/3.11/lib/python3.11/traceback.py:416: in _extract_from_extended_frame_gen
    for f, (lineno, end_lineno, colno, end_colno) in frame_gen:
        capture_locals = False
        fnames     = set()
        frame_gen  = <generator object _walk_tb_with_full_positions at 0x10d50c3c0>
        klass      = <class 'traceback.StackSummary'>
        limit      = None
        lookup_lines = True
        result     = []
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

tb = <traceback object at 0x10e3f4b00>

    def _walk_tb_with_full_positions(tb):
        # Internal version of walk_tb that yields full code positions including
        # end line and column information.
        while tb is not None:
>           positions = _get_code_position(tb.tb_frame.f_code, tb.tb_lasti)
E           AttributeError: 'frozenset' object has no attribute 'f_code'

tb         = <traceback object at 0x10e3f4b00>

/opt/local/Library/Frameworks/Python.framework/Versions/3.11/lib/python3.11/traceback.py:353: AttributeError
========================================== short test summary info ==========================================
FAILED openpyxl/tests/test_iter.py::test_read_single_cell_formula[False-='Sheet2 - Numbers'!D5] - Attribut...
=========================== 1 failed, 2467 passed, 16 skipped, 6 xfailed in 8.24s ===========================
ERROR: InvocationError for command /Users/charlieclark/Projects/openpyxl/.tox/py311/bin/pytest openpyxl (exited with code 1)
__________________________________________________ summary __________________________________________________
ERROR:   py311: commands failed

And an example from the Docker image at https://foss.heptapod.net/openpyxl/openpyxl/-/jobs/618571

Your environment

MacOS 10.15, official docker image (slim)
Python 3.11 beta 4 & 5

I suspect the issue is somewhere between pytest and Python3.11
@Themanwithoutaplan Themanwithoutaplan added the type-bug An unexpected behavior, bug, or error label Aug 9, 2022
@mdboom
Copy link
Contributor

mdboom commented Aug 9, 2022

Are you able to provide a standalone test case that reproduces the issue? Still inside pytest is probably fine, but it would be helpful to disentangle it from the rest of your test suite.

What version of pytest are you using?

@Themanwithoutaplan
Copy link
Author

Themanwithoutaplan commented Aug 9, 2022 via email

@iritkatriel
Copy link
Member

Any idea how you ended up with tb.tb_frame which is a frozenset?

>           positions = _get_code_position(tb.tb_frame.f_code, tb.tb_lasti)
[212](https://foss.heptapod.net/openpyxl/openpyxl/-/jobs/618571#L212)E           AttributeError: 'frozenset' object has no attribute 'f_code'
[213](https://foss.heptapod.net/openpyxl/openpyxl/-/jobs/618571#L213)tb         = <traceback object at 0x7f249c6c1f80>

@iritkatriel
Copy link
Member

Sorry, no the failure only seems to have when everything runs

What is "everything" exactly?

@iritkatriel
Copy link
Member

Since I can't reproduce on my end, could you try debugging with a monkey-patch of the traceback display code, along these lines?

import traceback

def my_walk_tb_with_full_positions(tb):
    # Internal version of walk_tb that yields full code positions including
    # end line and column information.
    prev_tb = None
    while tb is not None:
        if isinstance(tb.tb_frame, frozenset):       ##### play with this to get information about the error case
            prev_tb_frame = prev_tb.frame if prev_tb else None
            raise ValueError(f"{prev_tb_frame=}  {tb.tb_frame=}")
        prev_tb = tb
        positions = traceback._get_code_position(tb.tb_frame.f_code, tb.tb_lasti)
        # Yield tb_lineno when co_positions does not have a line number to
        # maintain behavior with walk_tb.
        if positions[0] is None:
            yield tb.tb_frame, (tb.tb_lineno, ) + positions[1:]
        else:
            yield tb.tb_frame, positions
        tb = tb.tb_next

traceback._walk_tb_with_full_positions = my_walk_tb_with_full_positions

@Themanwithoutaplan
Copy link
Author

Sorry, no the failure only seems to have when everything runs

What is "everything" exactly?

pytest -rf openpyxl or tox -e py311 openpyxl

@Themanwithoutaplan
Copy link
Author

Any idea how you ended up with tb.tb_frame which is a frozenset?

>           positions = _get_code_position(tb.tb_frame.f_code, tb.tb_lasti)
[212](https://foss.heptapod.net/openpyxl/openpyxl/-/jobs/618571#L212)E           AttributeError: 'frozenset' object has no attribute 'f_code'
[213](https://foss.heptapod.net/openpyxl/openpyxl/-/jobs/618571#L213)tb         = <traceback object at 0x7f249c6c1f80>

No. This is obviously a bug, which is why I'm reporting it but it's not in any of my code. I suspect this is coming from some kind of interaction between pytest and Python 3.11 in a race condition when lots of tests are run, which is the only way I can reproduce it.

@iritkatriel
Copy link
Member

It could be a bug in pytest, openpyxl, tox or python.

Please report it to the other projects so that they can investigate and, if the bug is in python, narrow it down to a small reproducer that we can look into.

@iritkatriel iritkatriel added the pending The issue will be closed if no feedback is provided label Aug 10, 2022
@Themanwithoutaplan
Copy link
Author

It's obviously not a bug in openpyxl. The same code relevant to the test hasn't been touched for years and the seg fault only appeared on CI last week and only with Python 3.11 which is why I submitted the bug. We1 test against Python ≥ 3.6, including PyPy, and the problem only occurs with Python 3.11 but can be reliably reproduced.

@iritkatriel
Copy link
Member

It's not a segfault, it's an exception.

If you can't reduce this to something that doesn't involve 3 third-party programs, or debug it like I suggested, then the next option is to report it to pytest and see if they can.

(they seem to be using frozensets for paths, so maybe they will know what happened).

@Themanwithoutaplan
Copy link
Author

It's not a segfault, it's an exception.
The initial report, linked to the CI log was a segfault that I was able to reproduce on a separate architecture. This was likely produced by whatever causes the exception, but it was still a segfault.

As the problem does not stem directly from the code being tested, or even from an individual test, see the extensive multiversion test history, I'm limited in what I can debug directly. I will report the problem to pytest but there's definitely some kind of combination with Python 3.11 and this is recent. I've been running CI against 3.11 since before the first beta. I do this so that the library can be used with Python 3.11 as soon as this is released but with failures like this I'll have to mark openpyxl as not suitable for use with Python 3.11.

From a relevant segfault

Using Docker executor with image python:3.11-rc ...
Pulling docker image python:3.11-rc ...
Using docker image sha256:cd09f507920ea95a499df7e5910ad041fa56adb5b51793ae9bebc3d85eb1f0d0 for python:3.11-rc ...
Preparing environment 00:01
Running on runner-d0d0b143-project-322-concurrent-1 via heptapod...
Getting source from version control 00:02
Reusing existing Mercurial repository
Changeset 67f1b0a00a722d593094b2bf73e1256a196c4fc1 is present
Updating to 67f1b0a00a722
0 files updated, 0 files merged, 0 files removed, 0 files unresolved
Executing "step_script" stage of the job script 15:12
$ python -V
Python 3.11.0b5
$ pip install -r requirements.txt
Requirement already satisfied: pip>=18.0 in /usr/local/lib/python3.11/site-packages (from -r requirements.txt (line 1)) (22.2)
Collecting lxml>=4.2.0
  Downloading lxml-4.9.1-cp311-cp311-manylinux_2_17_x86_64.manylinux2014_x86_64.manylinux_2_24_x86_64.whl (7.0 MB)
     ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 7.0/7.0 MB 47.3 MB/s eta 0:00:00
Collecting pytest
  Downloading pytest-7.1.2-py3-none-any.whl (297 kB)

@iritkatriel
Copy link
Member

From a relevant segfault

Your original report was about an exception being raised, and you twice referred to it as a segfault in followup comments. Is there a segfault?

I'm finding this bug report very confusing.

As the problem does not stem directly from the code being tested, or even from an individual test, see the extensive multiversion test history, I'm limited in what I can debug directly. I will report the problem to pytest but there's definitely some kind of combination with Python 3.11 and this is recent. I've been running CI against 3.11 since before the first beta. I do this so that the library can be used with Python 3.11 as soon as this is released but with failures like this I'll have to mark openpyxl as not suitable for use with Python 3.11.

I believe everything you say (I believed you the first time), but none of this is helping me fix anything.

@Themanwithoutaplan Themanwithoutaplan mentioned this issue Aug 10, 2022
Closed
3 tasks
@ericsnowcurrently
Copy link
Member

Were all the loaded extension modules built against the same (beta) version of Python that you ran when the failure happened?

@Themanwithoutaplan
Copy link
Author

Were all the loaded extension modules built against the same (beta) version of Python that you ran when the failure happened?
Yes, the CI it's always a fresh build and I ran tox -re when double-checking locally. I also did a clean clone of the repo in a Python 3.11 venv to see be exclude tox from the matrix of possible causes.

@iritkatriel
Copy link
Member

And an example from the Docker image at https://foss.heptapod.net/openpyxl/openpyxl/-/jobs/618571

Are you able to provide such a link for the last version of this testrun that does not fail?

@iritkatriel
Copy link
Member

And an example from the Docker image at https://foss.heptapod.net/openpyxl/openpyxl/-/jobs/618571

Are you able to provide such a link for the last version of this testrun that does not fail?

I think I found it: https://foss.heptapod.net/openpyxl/openpyxl/-/jobs/618303

Were there no ResourceWarnings then about 'sample.xlsx' not being closed?

@brandtbucher
Copy link
Member

I'm getting a different crash when attempting to reproduce:

(env311) brandtbucher@faster-cpython:~/openpyxl$ pip freeze
/home/brandtbucher/env311/lib/python3.11/site-packages/pip/_vendor/certifi/core.py:50: DeprecationWarning: path is deprecated. Use files() instead. Refer to https://importlib-resources.readthedocs.io/en/latest/using.html#migrating-from-legacy for migration advice.
  _CACERT_CTX = get_path("pip._vendor.certifi", "cacert.pem")
/home/brandtbucher/env311/lib/python3.11/site-packages/pip/_vendor/packaging/version.py:111: DeprecationWarning: Creating a LegacyVersion has been deprecated and will be removed in the next major release
  warnings.warn(
attrs==22.1.0
distlib==0.3.5
et-xmlfile==1.1.0
filelock==3.8.0
iniconfig==1.1.1
lxml==4.9.1
numpy==1.23.1
# Editable install with no version control (openpyxl==3.1.0b1)
-e /home/brandtbucher/openpyxl
packaging==21.3
pandas==1.4.3
Pillow==9.2.0
platformdirs==2.5.2
pluggy==1.0.0
py==1.11.0
pyparsing==3.0.9
pytest==7.1.2
python-dateutil==2.8.2
pytz==2022.1
six==1.16.0
toml==0.10.2
tomli==2.0.1
tox==3.25.1
virtualenv==20.16.3

(env311) brandtbucher@faster-cpython:~/openpyxl$ pytest -rf openpyxl
=============================== test session starts ===============================
platform linux -- Python 3.11.0rc1+, pytest-7.1.2, pluggy-1.0.0
rootdir: /home/brandtbucher/openpyxl, configfile: pytest.ini
collected 2491 items                                                              

openpyxl/cell/tests/test_cell.py ..........................Traceback (most recent call last):
  File "/home/brandtbucher/env311/lib/python3.11/site-packages/_pytest/runner.py", line 136, in runtestprotocol
    item.funcargs = None  # type: ignore[attr-defined]
    ^^^^^^^^^^^^^
ResourceWarning: Object of type Timestamp is not untracked before destruction
........x....... [  1%]
.................                                                           [  2%]
openpyxl/cell/tests/test_read_only.py .........                             [  2%]
openpyxl/cell/tests/test_rich_text.py .................                     [  3%]
openpyxl/cell/tests/test_text.py ............                               [  3%]
openpyxl/cell/tests/test_writer.py ........................................ [  5%]
...............                                                             [  6%]
openpyxl/chart/tests/test_3d.py ....                                        [  6%]
openpyxl/chart/tests/test_area_chart.py .....                               [  6%]
openpyxl/chart/tests/test_axis.py .................                         [  7%]
openpyxl/chart/tests/test_bar_chart.py ......                               [  7%]
openpyxl/chart/tests/test_bubble_chart.py ..                                [  7%]
openpyxl/chart/tests/test_chart.py ..................                       [  8%]
openpyxl/chart/tests/test_chartspace.py ........                            [  8%]
openpyxl/chart/tests/test_data_source.py ..................                 [  9%]
openpyxl/chart/tests/test_error_bar.py ..                                   [  9%]
openpyxl/chart/tests/test_label.py ....                                     [  9%]
openpyxl/chart/tests/test_layout.py ...                                     [  9%]
openpyxl/chart/tests/test_legend.py ....                                    [  9%]
openpyxl/chart/tests/test_line_chart.py .....                               [  9%]
openpyxl/chart/tests/test_marker.py ....                                    [ 10%]
openpyxl/chart/tests/test_picture.py ..                                     [ 10%]
openpyxl/chart/tests/test_pie_chart.py .........                            [ 10%]
openpyxl/chart/tests/test_pivot.py ....                                     [ 10%]
openpyxl/chart/tests/test_plotarea.py ............                          [ 11%]
openpyxl/chart/tests/test_print.py ....                                     [ 11%]
openpyxl/chart/tests/test_radar_chart.py ..                                 [ 11%]
openpyxl/chart/tests/test_reader.py ...                                     [ 11%]
openpyxl/chart/tests/test_reference.py ..........                           [ 11%]
openpyxl/chart/tests/test_scatter_chart.py ..                               [ 12%]
openpyxl/chart/tests/test_series.py .........                               [ 12%]
openpyxl/chart/tests/test_series_factory.py .......                         [ 12%]
openpyxl/chart/tests/test_shapes.py ..                                      [ 12%]
openpyxl/chart/tests/test_stock_chart.py ..                                 [ 12%]
openpyxl/chart/tests/test_surface_chart.py ........                         [ 13%]
openpyxl/chart/tests/test_text.py .....                                     [ 13%]
openpyxl/chart/tests/test_title.py ...                                      [ 13%]
openpyxl/chart/tests/test_trendline.py ....                                 [ 13%]
openpyxl/chart/tests/test_updown_bars.py ..                                 [ 13%]
openpyxl/chartsheet/tests/test_chartsheet.py ....                           [ 13%]
openpyxl/chartsheet/tests/test_custom.py ....                               [ 14%]
openpyxl/chartsheet/tests/test_properties.py ..                             [ 14%]
openpyxl/chartsheet/tests/test_protection.py ...                            [ 14%]
openpyxl/chartsheet/tests/test_publish.py ....                              [ 14%]
openpyxl/chartsheet/tests/test_relation.py ....                             [ 14%]
openpyxl/chartsheet/tests/test_views.py ....                                [ 14%]
openpyxl/comments/tests/test_author.py ..                                   [ 14%]
openpyxl/comments/tests/test_comment.py ....                                [ 14%]
openpyxl/comments/tests/test_comment_reader.py ...                          [ 15%]
openpyxl/comments/tests/test_comment_sheet.py ......                        [ 15%]
openpyxl/comments/tests/test_shape_writer.py ....                           [ 15%]
openpyxl/compat/tests/test_compat.py ........s.....                         [ 16%]
openpyxl/descriptors/tests/test_base.py ................................... [ 17%]
.............                                                               [ 17%]
openpyxl/descriptors/tests/test_excel.py ................................   [ 19%]
openpyxl/descriptors/tests/test_namespace.py ...                            [ 19%]
openpyxl/descriptors/tests/test_nested.py .........................         [ 20%]
openpyxl/descriptors/tests/test_sequence.py ...................             [ 21%]
openpyxl/descriptors/tests/test_serialisable.py ...............             [ 21%]
openpyxl/drawing/tests/test_color.py ............                           [ 22%]
openpyxl/drawing/tests/test_connector.py x.                                 [ 22%]
openpyxl/drawing/tests/test_descriptors.py .                                [ 22%]
openpyxl/drawing/tests/test_drawing.py ........                             [ 22%]
openpyxl/drawing/tests/test_effect.py ......                                [ 22%]
openpyxl/drawing/tests/test_fill.py .................                       [ 23%]
openpyxl/drawing/tests/test_geometry.py ................                    [ 24%]
openpyxl/drawing/tests/test_graphic.py ...........xx..                      [ 24%]
openpyxl/drawing/tests/test_image.py s.....                                 [ 25%]
openpyxl/drawing/tests/test_line.py .......                                 [ 25%]
openpyxl/drawing/tests/test_picture.py ........                             [ 25%]
openpyxl/drawing/tests/test_properties.py ..........                        [ 26%]
openpyxl/drawing/tests/test_relation.py ..                                  [ 26%]
openpyxl/drawing/tests/test_spreadsheet_drawing.py ........................ [ 27%]
..                                                                          [ 27%]
openpyxl/drawing/tests/test_text.py ..............                          [ 27%]
openpyxl/formatting/tests/test_formatting.py .......                        [ 28%]
openpyxl/formatting/tests/test_rule.py ................................     [ 29%]
openpyxl/formula/tests/test_tokenizer.py .................................. [ 30%]
........................................................................... [ 33%]
........................................................................... [ 36%]
..........                                                                  [ 37%]
openpyxl/formula/tests/test_translate.py .................................. [ 38%]
........................................................................... [ 41%]
............                                                                [ 41%]
openpyxl/packaging/tests/test_core.py .......                               [ 42%]
openpyxl/packaging/tests/test_custom.py ..............................      [ 43%]
openpyxl/packaging/tests/test_extended.py ..                                [ 43%]
openpyxl/packaging/tests/test_interface.py .                                [ 43%]
openpyxl/packaging/tests/test_manifest.py ....................              [ 44%]
openpyxl/packaging/tests/test_pivot.py ..                                   [ 44%]
openpyxl/packaging/tests/test_relationship.py ......                        [ 44%]
openpyxl/packaging/tests/test_workbook.py ...                               [ 44%]
openpyxl/pivot/tests/test_cache.py ..........................               [ 45%]
openpyxl/pivot/tests/test_fields.py ..............                          [ 46%]
openpyxl/pivot/tests/test_record.py .....                                   [ 46%]
openpyxl/pivot/tests/test_table.py ..............................           [ 47%]
openpyxl/reader/tests/test_drawings.py ....                                 [ 47%]
openpyxl/reader/tests/test_excel.py ...............................         [ 49%]
openpyxl/reader/tests/test_strings.py ...                                   [ 49%]
openpyxl/reader/tests/test_workbook.py ..........                           [ 49%]
openpyxl/styles/tests/test_alignments.py ...                                [ 49%]
openpyxl/styles/tests/test_borders.py ..                                    [ 49%]
openpyxl/styles/tests/test_cell_style.py ..........                         [ 50%]
openpyxl/styles/tests/test_colors.py ..................                     [ 51%]
openpyxl/styles/tests/test_differential.py ....                             [ 51%]
openpyxl/styles/tests/test_fills.py .............................           [ 52%]
openpyxl/styles/tests/test_fonts.py ....                                    [ 52%]
openpyxl/styles/tests/test_named_style.py .........................         [ 53%]
openpyxl/styles/tests/test_number_style.py ................................ [ 54%]
.............................................                               [ 56%]
openpyxl/styles/tests/test_protection.py ..                                 [ 56%]
openpyxl/styles/tests/test_proxy.py .....                                   [ 56%]
openpyxl/styles/tests/test_styleable.py ..........                          [ 57%]
openpyxl/styles/tests/test_stylesheet.py ....................               [ 58%]
openpyxl/styles/tests/test_table.py ......                                  [ 58%]
openpyxl/tests/test_backend.py ..                                           [ 58%]
openpyxl/tests/test_iter.py ..........................................Fatal Python error: Aborted

Current thread 0x00007fdcf6c64280 (most recent call first):
  Garbage-collecting
  File "/home/brandtbucher/openpyxl/openpyxl/descriptors/serialisable.py", line 160 in __iter__
  File "/home/brandtbucher/openpyxl/openpyxl/descriptors/serialisable.py", line 118 in to_tree
  File "/home/brandtbucher/openpyxl/openpyxl/descriptors/serialisable.py", line 154 in to_tree
  File "/home/brandtbucher/openpyxl/openpyxl/descriptors/serialisable.py", line 233 in __copy__
  File "/home/brandtbucher/cpython/Lib/copy.py", line 84 in copy
  File "/home/brandtbucher/openpyxl/openpyxl/workbook/workbook.py", line 116 in _setup_styles
  File "/home/brandtbucher/openpyxl/openpyxl/workbook/workbook.py", line 74 in __init__
  File "/home/brandtbucher/openpyxl/openpyxl/reader/workbook.py", line 34 in __init__
  File "/home/brandtbucher/openpyxl/openpyxl/reader/excel.py", line 152 in read_workbook
  File "/home/brandtbucher/openpyxl/openpyxl/reader/excel.py", line 291 in read
  File "/home/brandtbucher/openpyxl/openpyxl/reader/excel.py", line 346 in load_workbook
  File "/home/brandtbucher/openpyxl/openpyxl/tests/test_iter.py", line 268 in test_read_single_cell_formula
  File "/home/brandtbucher/env311/lib/python3.11/site-packages/_pytest/python.py", line 192 in pytest_pyfunc_call
  File "/home/brandtbucher/env311/lib/python3.11/site-packages/pluggy/_callers.py", line 39 in _multicall
  File "/home/brandtbucher/env311/lib/python3.11/site-packages/pluggy/_manager.py", line 80 in _hookexec
  File "/home/brandtbucher/env311/lib/python3.11/site-packages/pluggy/_hooks.py", line 265 in __call__
  File "/home/brandtbucher/env311/lib/python3.11/site-packages/_pytest/python.py", line 1761 in runtest
  File "/home/brandtbucher/env311/lib/python3.11/site-packages/_pytest/runner.py", line 166 in pytest_runtest_call
  File "/home/brandtbucher/env311/lib/python3.11/site-packages/pluggy/_callers.py", line 39 in _multicall
  File "/home/brandtbucher/env311/lib/python3.11/site-packages/pluggy/_manager.py", line 80 in _hookexec
  File "/home/brandtbucher/env311/lib/python3.11/site-packages/pluggy/_hooks.py", line 265 in __call__
  File "/home/brandtbucher/env311/lib/python3.11/site-packages/_pytest/runner.py", line 259 in <lambda>
  File "/home/brandtbucher/env311/lib/python3.11/site-packages/_pytest/runner.py", line 338 in from_call
  File "/home/brandtbucher/env311/lib/python3.11/site-packages/_pytest/runner.py", line 258 in call_runtest_hook
  File "/home/brandtbucher/env311/lib/python3.11/site-packages/_pytest/runner.py", line 219 in call_and_report
  File "/home/brandtbucher/env311/lib/python3.11/site-packages/_pytest/runner.py", line 130 in runtestprotocol
  File "/home/brandtbucher/env311/lib/python3.11/site-packages/_pytest/runner.py", line 111 in pytest_runtest_protocol
  File "/home/brandtbucher/env311/lib/python3.11/site-packages/pluggy/_callers.py", line 39 in _multicall
  File "/home/brandtbucher/env311/lib/python3.11/site-packages/pluggy/_manager.py", line 80 in _hookexec
  File "/home/brandtbucher/env311/lib/python3.11/site-packages/pluggy/_hooks.py", line 265 in __call__
  File "/home/brandtbucher/env311/lib/python3.11/site-packages/_pytest/main.py", line 347 in pytest_runtestloop
  File "/home/brandtbucher/env311/lib/python3.11/site-packages/pluggy/_callers.py", line 39 in _multicall
  File "/home/brandtbucher/env311/lib/python3.11/site-packages/pluggy/_manager.py", line 80 in _hookexec
  File "/home/brandtbucher/env311/lib/python3.11/site-packages/pluggy/_hooks.py", line 265 in __call__
  File "/home/brandtbucher/env311/lib/python3.11/site-packages/_pytest/main.py", line 322 in _main
  File "/home/brandtbucher/env311/lib/python3.11/site-packages/_pytest/main.py", line 268 in wrap_session
  File "/home/brandtbucher/env311/lib/python3.11/site-packages/_pytest/main.py", line 315 in pytest_cmdline_main
  File "/home/brandtbucher/env311/lib/python3.11/site-packages/pluggy/_callers.py", line 39 in _multicall
  File "/home/brandtbucher/env311/lib/python3.11/site-packages/pluggy/_manager.py", line 80 in _hookexec
  File "/home/brandtbucher/env311/lib/python3.11/site-packages/pluggy/_hooks.py", line 265 in __call__
  File "/home/brandtbucher/env311/lib/python3.11/site-packages/_pytest/config/__init__.py", line 164 in main
  File "/home/brandtbucher/env311/lib/python3.11/site-packages/_pytest/config/__init__.py", line 187 in console_main
  File "/home/brandtbucher/env311/bin/pytest", line 8 in <module>

Extension modules: numpy.core._multiarray_umath, numpy.core._multiarray_tests, numpy.linalg._umath_linalg, numpy.fft._pocketfft_internal, numpy.random._common, numpy.random.bit_generator, numpy.random._bounded_integers, numpy.random._mt19937, numpy.random.mtrand, numpy.random._philox, numpy.random._pcg64, numpy.random._sfc64, numpy.random._generator, lxml._elementpath, lxml.etree, PIL._imaging, pandas._libs.tslibs.dtypes, pandas._libs.tslibs.base, pandas._libs.tslibs.np_datetime, pandas._libs.tslibs.nattype, pandas._libs.tslibs.timezones, pandas._libs.tslibs.ccalendar, pandas._libs.tslibs.tzconversion, pandas._libs.tslibs.strptime, pandas._libs.tslibs.fields, pandas._libs.tslibs.timedeltas, pandas._libs.tslibs.timestamps, pandas._libs.properties, pandas._libs.tslibs.offsets, pandas._libs.tslibs.parsing, pandas._libs.tslibs.conversion, pandas._libs.tslibs.period, pandas._libs.tslibs.vectorized, pandas._libs.ops_dispatch, pandas._libs.missing, pandas._libs.hashtable, pandas._libs.algos, pandas._libs.interval, pandas._libs.tslib, pandas._libs.lib, pandas._libs.hashing, pandas._libs.ops, pandas._libs.arrays, pandas._libs.index, pandas._libs.join, pandas._libs.sparse, pandas._libs.reduction, pandas._libs.indexing, pandas._libs.internals, pandas._libs.writers, pandas._libs.window.aggregations, pandas._libs.window.indexers, pandas._libs.reshape, pandas._libs.groupby, pandas._libs.testing, pandas._libs.parsers, pandas._libs.json, PIL._webp (total: 58)
Aborted (core dumped)

This reproduces consistently for me, but only if I run the entire suite (not any subset of the test files that I've tried).

@iritkatriel
Copy link
Member

That resource warning is new: f40bc7f

@brandtbucher
Copy link
Member

Let me try running with a non-debug build...

@brandtbucher
Copy link
Member

Okay, with a non-debug build I can reproduce this reliably too (but it's a set instead of a frozenset):

AttributeError: 'set' object has no attribute 'f_code'

___________ test_read_single_cell_formula[False-='Sheet2 - Numbers'!D5] ___________

exc = <class 'ResourceWarning'>
value = ResourceWarning("unclosed file <_io.BufferedReader name='sample.xlsx'>")
tb = <traceback object at 0x7f3a89f47000>, limit = None, chain = True

    def format_exception(exc, /, value=_sentinel, tb=_sentinel, limit=None, \
                         chain=True):
        """Format a stack trace and the exception information.
    
        The arguments have the same meaning as the corresponding arguments
        to print_exception().  The return value is a list of strings, each
        ending in a newline and some containing internal newlines.  When
        these lines are concatenated and printed, exactly the same text is
        printed as does print_exception().
        """
        value, tb = _parse_value_tb(exc, value, tb)
>       te = TracebackException(type(value), value, tb, limit=limit, compact=True)

chain      = True
exc        = <class 'ResourceWarning'>
limit      = None
tb         = <traceback object at 0x7f3a89f47000>
value      = ResourceWarning("unclosed file <_io.BufferedReader name='sample.xlsx'>")

/home/brandtbucher/cpython/Lib/traceback.py:139: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
/home/brandtbucher/cpython/Lib/traceback.py:688: in __init__
    self.stack = StackSummary._extract_from_extended_frame_gen(
        _seen      = {139889394044544}
        capture_locals = False
        compact    = True
        exc_traceback = <traceback object at 0x7f3a89f47000>
        exc_type   = <class 'ResourceWarning'>
        exc_value  = ResourceWarning("unclosed file <_io.BufferedReader name='sample.xlsx'>")
        is_recursive_call = False
        limit      = None
        lookup_lines = True
        max_group_depth = 10
        max_group_width = 15
        self       = <traceback.TracebackException object at 0x7f3a89c03ed0>
/home/brandtbucher/cpython/Lib/traceback.py:416: in _extract_from_extended_frame_gen
    for f, (lineno, end_lineno, colno, end_colno) in frame_gen:
        capture_locals = False
        fnames     = set()
        frame_gen  = <generator object _walk_tb_with_full_positions at 0x7f3a89f312a0>
        klass      = <class 'traceback.StackSummary'>
        limit      = None
        lookup_lines = True
        result     = []
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

tb = <traceback object at 0x7f3a89f47000>

    def _walk_tb_with_full_positions(tb):
        # Internal version of walk_tb that yields full code positions including
        # end line and column information.
        while tb is not None:
>           positions = _get_code_position(tb.tb_frame.f_code, tb.tb_lasti)
E           AttributeError: 'set' object has no attribute 'f_code'

tb         = <traceback object at 0x7f3a89f47000>

/home/brandtbucher/cpython/Lib/traceback.py:353: AttributeError

@brandtbucher
Copy link
Member

@pablogsal, smells like poorly-behaved GC objects to me?

@pablogsal
Copy link
Member

@pablogsal, smells like poorly-behaved GC objects to me?

If you can reproduce, could you bisect?

@brandtbucher
Copy link
Member

Okay, I'm able to reproduce without any third-party extension modules loaded. Trying to remove pure-Python dependencies now.

@brandtbucher
Copy link
Member

There's still a pile of Python dependencies I'd like out of the way first.

@brandtbucher
Copy link
Member

It's not just frames:

AttributeError: 'dict' object has no attribute 'co_positions'

@iritkatriel iritkatriel removed the pending The issue will be closed if no feedback is provided label Aug 10, 2022
@iritkatriel
Copy link
Member

@brandtbucher does this make a difference by any chance?

diff --git a/Modules/_io/fileio.c b/Modules/_io/fileio.c
index 00859978e8..322e98085c 100644
--- a/Modules/_io/fileio.c
+++ b/Modules/_io/fileio.c
@@ -513,10 +513,10 @@ fileio_clear(fileio *self)
 static void
 fileio_dealloc(fileio *self)
 {
+    _PyObject_GC_UNTRACK(self);
     self->finalizing = 1;
     if (_PyIOBase_finalize((PyObject *) self) < 0)
         return;
-    _PyObject_GC_UNTRACK(self);
     if (self->weakreflist != NULL)
         PyObject_ClearWeakRefs((PyObject *) self);
     Py_CLEAR(self->dict);

@brandtbucher
Copy link
Member

git bisect says #26974 is to blame. Reverting that commit fixes the test run, but I'm not convinced that it's the root cause.

@pablogsal
Copy link
Member

This are the values that makes it fail:

prev_instr= 0x557ba26ca7c8
_PyCode_CODE(frame->f_code)= 0x557ba26ca7c8
frame->f_code->_co_firsttraceable)= 2

@brandtbucher
Copy link
Member

Ah, so the warning is what makes the bug start breaking stuff more visibly. Got it.

@brandtbucher
Copy link
Member

This are the values that makes it fail:

prev_instr= 0x557ba26ca7c8
_PyCode_CODE(frame->f_code)= 0x557ba26ca7c8
frame->f_code->_co_firsttraceable)= 2

Wait, but those values wouldn't make frame->prev_instr < _PyCode_CODE(frame->f_code) + frame->f_code->_co_firsttraceable fail. What is frame->owner?

@pablogsal
Copy link
Member

What is frame->owner?

0

@brandtbucher
Copy link
Member

I don't see how _PyFrame_IsIncomplete is failing, then.

@pablogsal
Copy link
Member

Let me check then what's going on, I may be miscopied the values

@brandtbucher
Copy link
Member

Oh, wait, we're inverting the condition in the assert. That makes sense now.

@pablogsal
Copy link
Member

Somehow the problem seems to be that the gc is triggering at the start of the generator, before it has actually even started

@pablogsal
Copy link
Member

pablogsal commented Aug 11, 2022 •
edited
Loading

The framer is running Serialisable.__iter__ and up the stack the gc is being triggered when calling:

PyGenObject *gen = (PyGenObject *)_Py_MakeCoro(frame->f_func);

that coroutine creation triggers the GC, that deallocates one of these IO objects that warns and that wants a frame, but the frame that is running is not even started (that _PyMakeCoro is in RETURN_GENERATOR ).

@pablogsal
Copy link
Member

This is the bytecode for that thing:

Disassembly of <code object __iter__ at 0x7f86dbd64830, file "openpyxl/descriptors/serialisable.py", line 160>:
160           0 RETURN_GENERATOR
              2 POP_TOP
              4 RESUME                   0

161           6 LOAD_FAST                0 (self)
              8 LOAD_ATTR                0 (__attrs__)
             18 GET_ITER
        >>   20 FOR_ITER               147 (to 316)
             22 STORE_FAST               1 (attr)

the gc is triggering in opcode 0: RETURN_GENERATOR

@pablogsal
Copy link
Member

pablogsal commented Aug 11, 2022 •
edited
Loading

Ok, here is a sort-of-minimal reproducer (not everything here is essential):

import gc
gc.set_threshold(1,1,1)

class GCHello:
    def __del__(self):
        print("Destroyed from gc")

def foo():
   yield
   del l
   gc.collect()
   yield

x = open("my_file")
l = [x, GCHello()]
l.append(l)
del x
del l
f = foo()
next(f)
next(f)

Running this:

./python lel.py
Destroyed from gc
python: ./Include/internal/pycore_frame.h:163: _PyFrame_GetFrameObject: Assertion `!_PyFrame_IsIncomplete(frame)' failed.
[1]    1872503 IOT instruction (core dumped)  ./python lel.py

@pablogsal
Copy link
Member

pablogsal commented Aug 11, 2022 •
edited
Loading

Is 2AM in London, I'm going to sleep 😴

Good hunt!

@brandtbucher
Copy link
Member

Nice debugging! I'm still not sure how this new bug relates to the weird tb_frame bug, though. Does the interpreter state just get messed up that badly if the assert is turned off?

@pablogsal
Copy link
Member

Nice debugging! I'm still not sure how this new bug relates to the weird tb_frame bug, though. Does the interpreter state just get messed up that badly if the assert is turned off?

I think there is some ownership problems with they frame and it gets deleted while someone is holding to it and then you get garbage.

@brandtbucher
Copy link
Member

@markshannon, looks like assert(!_PyFrame_IsIncomplete(frame)) in _PyFrame_GetFrameObject is invalid when generator creation kicks off a GC run and one of the finalizers grabs the frame one level up.

@markshannon markshannon self-assigned this Aug 11, 2022
@markshannon
Copy link
Member

@pablogsal Thanks for the reproducer.

In theory, incomplete frames should be skipped in tracebacks and the like. But it looks like we don't do that in PyThreadState_GetFrame(). Let me fix that.

This was referenced Aug 11, 2022
Merged
Merged
miss-islington pushed a commit to miss-islington/cpython that referenced this issue Aug 11, 2022
@markshannon @miss-islington
pythonGH-95818: Skip incomplete frames in PyThreadState_GetFrame (p…
06cf327 
…ythonGH-95886)

(cherry picked from commit 1b46d11)

Co-authored-by: Mark Shannon <mark@hotpy.org>
markshannon added a commit that referenced this issue Aug 11, 2022
@markshannon
GH-95818: Skip incomplete frames in PyThreadState_GetFrame (GH-95886)
1b46d11
pablogsal pushed a commit that referenced this issue Aug 12, 2022
@miss-islington @markshannon
GH-95818: Skip incomplete frames in PyThreadState_GetFrame (GH-95886)…
6fc90c1 
… (#95890)

(cherry picked from commit 1b46d11)

Co-authored-by: Mark Shannon <mark@hotpy.org>

Co-authored-by: Mark Shannon <mark@hotpy.org>
@markshannon
Copy link
Member

Is this fixed now?

@Themanwithoutaplan
Copy link
Author

Themanwithoutaplan commented Aug 24, 2022 via email

@pablogsal
Copy link
Member

I'm closing this as the underlying issue seems to be fixed. Please reopen if we are missing something.

@sweeneyde
Copy link
Member

The added test case looks delicate, so I don't want to disrupt it too much, but it looks like it's emitting the following warning on some buildbots:

/home/buildbot/buildarea/3.x.cstratak-fedora-stable-ppc64le.refleak/build/Lib/test/test_frame.py:258: ResourceWarning: unclosed file <_io.TextIOWrapper name='/home/buildbot/buildarea/3.x.cstratak-fedora-stable-ppc64le.refleak/build/Lib/test/test_frame.py' mode='r' encoding='UTF-8'>
ResourceWarning: Enable tracemalloc to get the object allocation traceback
./home/buildbot/buildarea/3.x.cstratak-fedora-stable-ppc64le.refleak/build/Lib/test/test_frame.py:258: ResourceWarning: unclosed file <_io.TextIOWrapper name='/home/buildbot/buildarea/3.x.cstratak-fedora-stable-ppc64le.refleak/build/Lib/test/test_frame.py' mode='r' encoding='UTF-8'>
ResourceWarning: Enable tracemalloc to get the object allocation traceback
./home/buildbot/buildarea/3.x.cstratak-fedora-stable-ppc64le.refleak/build/Lib/test/test_frame.py:258: ResourceWarning: unclosed file <_io.TextIOWrapper name='/home/buildbot/buildarea/3.x.cstratak-fedora-stable-ppc64le.refleak/build/Lib/test/test_frame.py' mode='r' encoding='UTF-8'>
ResourceWarning: Enable tracemalloc to get the object allocation traceback
./home/buildbot/buildarea/3.x.cstratak-fedora-stable-ppc64le.refleak/build/Lib/test/test_frame.py:258: ResourceWarning: unclosed file <_io.TextIOWrapper name='/home/buildbot/buildarea/3.x.cstratak-fedora-stable-ppc64le.refleak/build/Lib/test/test_frame.py' mode='r' encoding='UTF-8'>
ResourceWarning: Enable tracemalloc to get the object allocation traceback
./home/buildbot/buildarea/3.x.cstratak-fedora-stable-ppc64le.refleak/build/Lib/test/test_frame.py:258: ResourceWarning: unclosed file <_io.TextIOWrapper name='/home/buildbot/buildarea/3.x.cstratak-fedora-stable-ppc64le.refleak/build/Lib/test/test_frame.py' mode='r' encoding='UTF-8'>
ResourceWarning: Enable tracemalloc to get the object allocation traceback
./home/buildbot/buildarea/3.x.cstratak-fedora-stable-ppc64le.refleak/build/Lib/test/test_frame.py:258: ResourceWarning: unclosed file <_io.TextIOWrapper name='/home/buildbot/buildarea/3.x.cstratak-fedora-stable-ppc64le.refleak/build/Lib/test/test_frame.py' mode='r' encoding='UTF-8'>
ResourceWarning: Enable tracemalloc to get the object allocation traceback

Should this be run in a separate process or have the warnings suppressed or something?

@sweeneyde
Copy link
Member

I opened #96696

@brandtbucher brandtbucher mentioned this issue Sep 21, 2022
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@markshannon markshannon

@brandtbucher brandtbucher

Labels
3.11 only security fixes 3.12 bugs and security fixes release-blocker type-bug An unexpected behavior, bug, or error type-crash A hard crash of the interpreter, possibly with a core dump
Projects
Release and Deferred blockers 🚫
Archived in project
Milestone
No milestone
Development

No branches or pull requests
8 participants
@mdboom @iritkatriel @Themanwithoutaplan @ericsnowcurrently @markshannon @pablogsal @sweeneyde @brandtbucher