Exception context set to string by BufferedWriter.close()

[vadmium]

BPO	21677
Nosy	@pitrou, @benjaminp, @ned-deily, @vadmium, @serhiy-storchaka
Files	io_nonnormalized_error_on_close.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 2014-06-11.05:32:09.218>
created_at = <Date 2014-06-06.06:49:21.773>
labels = ['type-bug', 'expert-IO']
title = 'Exception context set to string by BufferedWriter.close()'
updated_at = <Date 2014-06-11.05:32:09.216>
user = 'https://github.com/vadmium'

bugs.python.org fields:

activity = <Date 2014-06-11.05:32:09.216>
actor = 'serhiy.storchaka'
assignee = 'serhiy.storchaka'
closed = True
closed_date = <Date 2014-06-11.05:32:09.218>
closer = 'serhiy.storchaka'
components = ['IO']
creation = <Date 2014-06-06.06:49:21.773>
creator = 'martin.panter'
dependencies = []
files = ['35509']
hgrepos = []
issue_num = 21677
keywords = ['patch']
message_count = 8.0
messages = ['219864', '219931', '220083', '220103', '220213', '220216', '220232', '220234']
nosy_count = 7.0
nosy_names = ['pitrou', 'benjamin.peterson', 'ned.deily', 'stutzbach', 'python-dev', 'martin.panter', 'serhiy.storchaka']
pr_nums = []
priority = 'normal'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = 'behavior'
url = 'https://bugs.python.org/issue21677'
versions = ['Python 3.4', 'Python 3.5']

[vadmium]

I made a writer class whose write() and flush() methods (unintentionally) triggered exceptions. I wrapped this in a BufferedWriter. When close() is called, the resulting exception has a string object in its __context__ attribute. Although the original error was my fault, it created a confusing chain reaction of exception reports.

>>> from io import BufferedWriter, RawIOBase
>>> import sys
>>> 
>>> class BuggyWriter(RawIOBase):
...     def writable(self): return True
...     def write(self, b): in_write  # Initial exception
...     def flush(self): raise Exception("In flush()")
... 
>>> output = BufferedWriter(BuggyWriter())
>>> output.write(b"data")
4
>>> output.close()  # Note the TypeError printed at the top
TypeError: print_exception(): Exception expected for value, str found

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "<stdin>", line 4, in flush
Exception: In flush()
>>> 
>>> sys.last_value
Exception('In flush()',)
>>> sys.last_value.__context__  # Should be exception, not string object
"name 'in_write' is not defined"
>>> 
>>> import traceback
>>> traceback.print_exception(sys.last_type, sys.last_value, sys.last_traceback)
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/lib/python3.4/traceback.py", line 169, in print_exception
    for line in _format_exception_iter(etype, value, tb, limit, chain):
  File "/usr/lib/python3.4/traceback.py", line 146, in _format_exception_iter
    for value, tb in values:
  File "/usr/lib/python3.4/traceback.py", line 138, in _iter_chain
    yield from it
  File "/usr/lib/python3.4/traceback.py", line 125, in _iter_chain
    context = exc.__context__
AttributeError: 'str' object has no attribute '__context__'

[serhiy-storchaka]

Here is a patch. It fixes also the same error in TextIOWrapper.

[python-dev]

New changeset a3b7b89da34f by Serhiy Storchaka in branch '3.4':
Issue bpo-21677: Fixed chaining nonnormalized exceptions in io close() methods.
http://hg.python.org/cpython/rev/a3b7b89da34f

New changeset d6ac4b6020b9 by Serhiy Storchaka in branch 'default':
Issue bpo-21677: Fixed chaining nonnormalized exceptions in io close() methods.
http://hg.python.org/cpython/rev/d6ac4b6020b9

[serhiy-storchaka]

Thank you Martin for your report.

[pitrou]

This changeset crashes test_io here:

test_close_error_on_close (test.test_io.CBufferedReaderTest) ... python: Objects/abstract.c:2091: PyObject_Call: Assertion `(result != ((void *)0) && !PyErr_Occurred()) || (result == ((void *)0) && PyErr_Occurred())' failed.
Fatal Python error: Aborted

Current thread 0x00007ff1b3264740 (most recent call first):
File "/home/antoine/cpython/default/Lib/test/test_io.py", line 793 in test_close_error_on_close
File "/home/antoine/cpython/default/Lib/unittest/case.py", line 577 in run
File "/home/antoine/cpython/default/Lib/unittest/case.py", line 625 in __call__
File "/home/antoine/cpython/default/Lib/unittest/suite.py", line 125 in run
File "/home/antoine/cpython/default/Lib/unittest/suite.py", line 87 in __call__
File "/home/antoine/cpython/default/Lib/unittest/suite.py", line 125 in run
File "/home/antoine/cpython/default/Lib/unittest/suite.py", line 87 in __call__
File "/home/antoine/cpython/default/Lib/unittest/suite.py", line 125 in run
File "/home/antoine/cpython/default/Lib/unittest/suite.py", line 87 in __call__
File "/home/antoine/cpython/default/Lib/unittest/runner.py", line 168 in run
File "/home/antoine/cpython/default/Lib/test/support/init.py", line 1724 in _run_suite
File "/home/antoine/cpython/default/Lib/test/support/init.py", line 1758 in run_unittest
File "/home/antoine/cpython/default/Lib/test/regrtest.py", line 1277 in <lambda>
File "/home/antoine/cpython/default/Lib/test/regrtest.py", line 1278 in runtest_inner
File "/home/antoine/cpython/default/Lib/test/regrtest.py", line 978 in runtest
File "/home/antoine/cpython/default/Lib/test/regrtest.py", line 763 in main
File "/home/antoine/cpython/default/Lib/test/regrtest.py", line 1562 in main_in_temp_cwd
File "/home/antoine/cpython/default/Lib/test/main.py", line 3 in <module>
File "/home/antoine/cpython/default/Lib/runpy.py", line 85 in _run_code
File "/home/antoine/cpython/default/Lib/runpy.py", line 170 in _run_module_as_main
Abandon

[pitrou]

gdb backtrace:

#0  0x00007ffff711ff79 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
#1  0x00007ffff7123388 in __GI_abort () at abort.c:89
#2  0x00007ffff7118e36 in __assert_fail_base (fmt=0x7ffff726a718 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", 
    assertion=assertion@entry=0x670d48 "(result != ((void *)0) && !PyErr_Occurred()) || (result == ((void *)0) && PyErr_Occurred())", file=file@entry=0x670332 "Objects/abstract.c", line=line@entry=2077, 
    function=function@entry=0x670ff6 <__PRETTY_FUNCTION__.10598> "PyObject_Call") at assert.c:92
#3  0x00007ffff7118ee2 in __GI___assert_fail (
    assertion=0x670d48 "(result != ((void *)0) && !PyErr_Occurred()) || (result == ((void *)0) && PyErr_Occurred())", 
    file=0x670332 "Objects/abstract.c", line=2077, function=0x670ff6 <__PRETTY_FUNCTION__.10598> "PyObject_Call") at assert.c:101
#4  0x0000000000461e89 in PyObject_Call (func=0x7ffff27013d8, arg=0x7ffff6638ef8, kw=0x0) at Objects/abstract.c:2076
#5  0x0000000000462f62 in PyObject_CallFunctionObjArgs 
(callable=0x7ffff27013d8) at Objects/abstract.c:2362
#6  0x0000000000463c46 in PyObject_IsSubclass (derived=0x911140 <_PyExc_OSError>, cls=0x911140 <_PyExc_OSError>)
    at Objects/abstract.c:2617
#7  0x00000000005cc591 in PyErr_NormalizeException (exc=0x7ffffffdc578, val=0x7ffffffdc580, tb=0x7ffffffdc588)
    at Python/errors.c:254
#8  0x0000000000639bc6 in buffered_close (self=0x7ffff7e6ad78, args=0x0) at ./Modules/_io/bufferedio.c:552

It seems PyErr_NormalizeException doesn't like being called with an exception set.

[python-dev]

New changeset a98fd4eeed40 by Serhiy Storchaka in branch '3.4':
PyErr_NormalizeException doesn't like being called with an exception set
http://hg.python.org/cpython/rev/a98fd4eeed40

New changeset 55c50c570098 by Serhiy Storchaka in branch 'default':
PyErr_NormalizeException doesn't like being called with an exception set
http://hg.python.org/cpython/rev/55c50c570098

[serhiy-storchaka]

Thank you Antoine. Perhaps this non-trivial code for chaining exceptions (repeated at least three times) should be extracted to separate function.