traceback.extract_stack() compatibility break in 3.5

[pitrou]

BPO	25108
Nosy	@ncoghlan, @pitrou, @larryhastings, @rbtcollins, @serhiy-storchaka
Files	traceback_extract_stack.patch

^{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 = 'https://github.com/serhiy-storchaka'
closed_at = <Date 2015-09-20.05:40:52.817>
created_at = <Date 2015-09-14.10:13:43.373>
labels = ['type-bug', 'library']
title = 'traceback.extract_stack() compatibility break in 3.5'
updated_at = <Date 2015-09-20.05:40:52.816>
user = 'https://github.com/pitrou'

bugs.python.org fields:

activity = <Date 2015-09-20.05:40:52.816>
actor = 'serhiy.storchaka'
assignee = 'serhiy.storchaka'
closed = True
closed_date = <Date 2015-09-20.05:40:52.817>
closer = 'serhiy.storchaka'
components = ['Library (Lib)']
creation = <Date 2015-09-14.10:13:43.373>
creator = 'pitrou'
dependencies = []
files = ['40462']
hgrepos = []
issue_num = 25108
keywords = ['patch']
message_count = 12.0
messages = ['250649', '250650', '250651', '250652', '250688', '250715', '250717', '250758', '250947', '251138', '251142', '251143']
nosy_count = 7.0
nosy_names = ['ncoghlan', 'pitrou', 'larry', 'rbcollins', 'Arfrever', 'python-dev', 'serhiy.storchaka']
pr_nums = []
priority = 'normal'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = 'behavior'
url = 'https://bugs.python.org/issue25108'
versions = ['Python 3.5', 'Python 3.6']

[pitrou]

This can be considered a regression, although perhaps it may not be desirable to fix it in a later release.

In 3.4:

>>> def f(): return traceback.extract_stack()
... 
>>> print([x[0:3] for x in f()])
[('<stdin>', 1, '<module>'), ('<stdin>', 1, 'f')]

In 3.5:

>>> print([x[0:3] for x in f()])
[('<stdin>', 1, '<module>'), ('<stdin>', 1, 'f'), ('/home/antoine/35/lib/python3.5/traceback.py', 201, 'extract_stack')]

Note how the traceback module suddenly appears in the extracted stack. This breaks any application which uses a fixed offset into the returned stack to look up for information.

[rbtcollins]

Hmm, I think we can fix this. Its leaking due to the use of a helper I think. So - we should just fix this [and add a test, since clearly the test coverage is insufficient]

[larryhastings]

Tracebacks aren't my forte, but this does smell like a regression and something that should be fixed.

My worry about things like this is that it isn't as much a "bug" as a "badly implemented interface". As in, that's the interface in 3.5, and people will depend on it, and we change it in a point release at our peril. (That's why I didn't permit "fixing" warnings.warn(stacklevel=) for 3.4.)

[pitrou]

Note the doc says "Extract the raw traceback from the current stack frame". The "current stack frame" may be assumed to be the caller's (as it is in previous Python releases).

Fortunately, this is also worked around by calling extract_stack(sys._getframe()).

[serhiy-storchaka]

Here is a patch that restores compatibility. There were no tests for print_stack(), format_stack(), and extract_stack() without arguments. New tests are passed with 3.4.

There is a difference between this bug and warnings.warn(stacklevel=) at import time. In the latter the behavior is changed when we specify the stacklevel and we can't workaround this besides change the specified stacklevel depending on Python version. In the former the behavior is changed only when we don't specify a frame. The workaround is version independed: specify the frame explicitly. Therefore we will not break a code with a workaround for 3.5.0, but will fix a code without workaround.

[ncoghlan]

Serhiy's explanation and fix look good to me.

[rbtcollins]

wouldn't changing walk_stack to add one more f_back be better? Seems odd to work around it...

[serhiy-storchaka]

wouldn't changing walk_stack to add one more f_back be better?

print_stack and format_stack need to add two more f_backs.

[python-dev]

New changeset c9fb4362fb9f by Serhiy Storchaka in branch '3.5':
Issue bpo-25108: Omitted internal frames in traceback functions print_stack(),
https://hg.python.org/cpython/rev/c9fb4362fb9f

New changeset 4e617566bcb6 by Serhiy Storchaka in branch 'default':
Issue bpo-25108: Omitted internal frames in traceback functions print_stack(),
https://hg.python.org/cpython/rev/4e617566bcb6

New changeset 9f57c937958f by Serhiy Storchaka in branch '3.4':
Issue bpo-25108: Backported tests for traceback functions print_stack(),
https://hg.python.org/cpython/rev/9f57c937958f

New changeset f6125114b55f by Serhiy Storchaka in branch '2.7':
Issue bpo-25108: Backported tests for traceback functions print_stack(),
https://hg.python.org/cpython/rev/f6125114b55f

[Arfrever]

New changeset f6125114b55f by Serhiy Storchaka in branch '2.7':
Issue bpo-25108: Backported tests for traceback functions print_stack(),
https://hg.python.org/cpython/rev/f6125114b55f

The new tests fail on 2.7 branch when Lib/test/test_traceback.pyc is present, because __file__ can contain path to *.pyc files in Python 2.
It is sufficient to run test_traceback twice to reproduce problem:

$ LD_LIBRARY_PATH="$(pwd)" ./python -m test.regrtest -v test_traceback
...
$ LD_LIBRARY_PATH="$(pwd)" ./python -m test.regrtest -v test_traceback
== CPython 2.7.10+ (2.7:fe84898fbe98, Sep 20 2015, 06:52:14) [GCC 4.9.3]
==   Linux-4.1.7 little-endian
==   /tmp/cpython/build/test_python_24845
Testing with flags: sys.flags(debug=0, py3k_warning=0, division_warning=0, division_new=0, inspect=0, interactive=0, optimize=0, dont_write_bytecode=0, no_user_site=0, no_site=0, ignore_environment=0, tabcheck=0, verbose=0, unicode=0, bytes_warning=0, hash_randomization=0)
[1/1] test_traceback
test_bad_indentation (test.test_traceback.TracebackCases) ... ok
test_base_exception (test.test_traceback.TracebackCases) ... ok
test_bug737473 (test.test_traceback.TracebackCases) ... ok
test_caret (test.test_traceback.TracebackCases) ... ok
test_format_exception_only_bad__str__ (test.test_traceback.TracebackCases) ... ok
test_nocaret (test.test_traceback.TracebackCases) ... ok
test_string_exception1 (test.test_traceback.TracebackCases) ... ok
test_string_exception2 (test.test_traceback.TracebackCases) ... ok
test_unicode (test.test_traceback.TracebackCases) ... ok
test_without_exception (test.test_traceback.TracebackCases) ... ok
test_format_stack (test.test_traceback.TracebackFormatTests) ... FAIL
test_print_stack (test.test_traceback.TracebackFormatTests) ... FAIL
test_traceback_format (test.test_traceback.TracebackFormatTests) ... ok
test_extract_stack (test.test_traceback.MiscTracebackCases) ... FAIL

======================================================================
FAIL: test_format_stack (test.test_traceback.TracebackFormatTests)
----------------------------------------------------------------------

Traceback (most recent call last):
  File "/tmp/cpython/Lib/test/test_traceback.py", line 232, in test_format_stack
    '    return traceback.format_stack()\n' % (__file__, lineno+1),
AssertionError: Lists differ: ['  File "/tmp/cpython/Lib/tes... != ['  File "/tmp/cpython/Lib/tes...

First differing element 0:
File "/tmp/cpython/Lib/test/test_traceback.py", line 226, in test_format_stack
result = fmt()

File "/tmp/cpython/Lib/test/test_traceback.pyc", line 226, in test_format_stack
result = fmt()

• [' File "/tmp/cpython/Lib/test/test_traceback.py", line 226, in test_format_stack\n result = fmt()\n',
  + [' File "/tmp/cpython/Lib/test/test_traceback.pyc", line 226, in test_format_stack\n result = fmt()\n',
  ? +

• ' File "/tmp/cpython/Lib/test/test_traceback.py", line 225, in fmt\n return traceback.format_stack()\n']
  + ' File "/tmp/cpython/Lib/test/test_traceback.pyc", line 225, in fmt\n return traceback.format_stack()\n']
  ? +

======================================================================
FAIL: test_print_stack (test.test_traceback.TracebackFormatTests)
----------------------------------------------------------------------

Traceback (most recent call last):
  File "/tmp/cpython/Lib/test/test_traceback.py", line 220, in test_print_stack
    '    traceback.print_stack()',
AssertionError: Lists differ: ['  File "/tmp/cpython/Lib/tes... != ['  File "/tmp/cpython/Lib/tes...

First differing element 0:
File "/tmp/cpython/Lib/test/test_traceback.py", line 214, in test_print_stack
File "/tmp/cpython/Lib/test/test_traceback.pyc", line 214, in test_print_stack

• [' File "/tmp/cpython/Lib/test/test_traceback.py", line 214, in test_print_stack',
  + [' File "/tmp/cpython/Lib/test/test_traceback.pyc", line 214, in test_print_stack',
  ? +

  ' prn()',

• ' File "/tmp/cpython/Lib/test/test_traceback.py", line 212, in prn',
  + ' File "/tmp/cpython/Lib/test/test_traceback.pyc", line 212, in prn',
  ? +

  ' traceback.print_stack()']

======================================================================
FAIL: test_extract_stack (test.test_traceback.MiscTracebackCases)
----------------------------------------------------------------------

Traceback (most recent call last):
  File "/tmp/cpython/Lib/test/test_traceback.py", line 248, in test_extract_stack
    (__file__, lineno+1, 'extract', 'return traceback.extract_stack()'),
AssertionError: Lists differ: [('/tmp/cpython/Lib/test/test_... != [('/tmp/cpython/Lib/test/test_...

First differing element 0:
('/tmp/cpython/Lib/test/test_traceback.py', 244, 'test_extract_stack', 'result = extract()')
('/tmp/cpython/Lib/test/test_traceback.pyc', 244, 'test_extract_stack', 'result = extract()')

• [('/tmp/cpython/Lib/test/test_traceback.py',
  + [('/tmp/cpython/Lib/test/test_traceback.pyc',
  ? +

    244,
    'test_extract_stack',
    'result = extract()'),
-  ('/tmp/cpython/Lib/test/test_traceback.py',
+  ('/tmp/cpython/Lib/test/test_traceback.pyc',
?                                           +

243,
'extract',
'return traceback.extract_stack()')]

----------------------------------------------------------------------
Ran 14 tests in 4.029s

FAILED (failures=3)
test test_traceback failed -- multiple errors occurred
1 test failed:
test_traceback

[python-dev]

New changeset 7e718bbf5152 by Serhiy Storchaka in branch '2.7':
Issue bpo-25108: Fixed test_traceback in the case when this test is run twice.
https://hg.python.org/cpython/rev/7e718bbf5152

[serhiy-storchaka]

Thank you Arfrever.