Suppressing printout of “Exception … ignored” mess

2020-07-03 05:26发布

问题:

There is a known issue in Python, where "close failed in file object destructor" when "Broken pipe" happens on stdout - Python tracker Issue 11380; also seen in python - Why does my Python3 script balk at piping its output to head or tail (sys module)? - Stack Overflow.

What I want to do, is printout the same custom message when this problem happens, in both Python 2.7 and Python 3+. So I prepare a test script, testprint.py and run it (snippets shown done in bash, Ubuntu 11.04):

$ cat > testprint.py <<"EOF"
import sys

def main():
  teststr = "Hello " * 5
  sys.stdout.write(teststr + "\n")

if __name__ == "__main__":
  main()
EOF

$ python2.7 testprint.py 
Hello Hello Hello Hello Hello 

$ python2.7 testprint.py | echo

close failed in file object destructor:
sys.excepthook is missing
lost sys.stderr

$ python3.2 testprint.py | echo

Exception IOError: (32, 'Broken pipe') in <_io.TextIOWrapper name='<stdout>' mode='w' encoding='UTF-8'> ignored

As expected from above links, there are two different messages. In Help with a piping error (velocityreviews.com), it is recommended to use sys.stdout.flush() to force Python 2 to register an IOError instead of that message; with that, we have:

$ cat > testprint.py <<"EOF"
import sys

def main():
  teststr = "Hello " * 5
  sys.stdout.write(teststr + "\n")
  sys.stdout.flush()

if __name__ == "__main__":
  main()
EOF

$ python2.7 testprint.py | echo

Traceback (most recent call last):
  File "testprint.py", line 9, in <module>
    main()
  File "testprint.py", line 6, in main
    sys.stdout.flush()
IOError: [Errno 32] Broken pipe

$ python3.2 testprint.py | echo

Traceback (most recent call last):
  File "testprint.py", line 9, in <module>
    main()
  File "testprint.py", line 6, in main
    sys.stdout.flush()
IOError: [Errno 32] Broken pipe
Exception IOError: (32, 'Broken pipe') in <_io.TextIOWrapper name='<stdout>' mode='w' encoding='UTF-8'> ignored

OK, getting closer... Now, the way to "ignore" these exceptions (or in my case, replace with a custom error message), is to handle them:

Ignore exceptions - comp.lang.python

> Is there any way to make [interpreter] ignore exceptions.
Nope. Either handle the exceptions or write code that doesn't generate exceptions.

... and as An Introduction to Python - Handling Exceptions notes, the way to do that is a try/except block. So let's try that:

$ cat > testprint.py <<"EOF"
import sys

def main():
  teststr = "Hello " * 5
  try:
    sys.stdout.write(teststr + "\n")
    sys.stdout.flush()
  except IOError:
    sys.stderr.write("Exc: " + str(sys.exc_info()[0]) + "\n")

if __name__ == "__main__":
  main()
EOF

$ python2.7 testprint.py | echo

Exc: <type 'exceptions.IOError'>

$ python3.2 testprint.py | echo

Exc: <class 'IOError'>
Exception IOError: (32, 'Broken pipe') in <_io.TextIOWrapper name='<stdout>' mode='w' encoding='UTF-8'> ignored

Ok, so try/except works as I expect it for Python 2.7 - but then, Python 3.2 both handles as expected, and still generates a Exception ... ignored message! What's the problem - isn't "except IOError" enough for Python 3? But it must be - otherwise it wouldn't have printed the custom "Exc:..." message!

So - what is the problem here, and why is the Exception ... ignored still printed in Python 3, even if I'm handling the exception? And more importantly, how do I handle it so the Exception ... ignored does not get printed anymore?

回答1:

Just some more notes about this - problem still not solved... first:

Issue 6294: Improve shutdown exception ignored message - Python tracker

This error message is generated in PyErr_WriteUnraisable, which is called from many contexts, including __del__ methods. A __del__ method called during shutdown is most likely what is generating the error you are speaking of, but as far as I know the __del__ method has no way to know that it is being called during shutdown in particular. So the proposed fix to the message won't work. [....]
However, because this is a message you can't even trap it should be completely safe to change it.

Well, thanks for this message that you cannot trap, very convenient. I believe this is somehow related to Ignore exceptions printed to stderr in del() - Stack Overflow, although that post (apparently) talks about custom __del__ methods.

Using a bit of the following resources:

  • Use Python’s sys.settrace() for fun and for profit | Reminiscential: of or pertaining to remembrance
  • Python Global Exception Handling - Stack Overflow

... I modified the script, so I overload all possible handlers I can, to see if there isn't a space somewhere where I can "handle" this exception so it isn't "ignored":

import sys
import atexit
import signal
import inspect, pprint

def signalPIPE_handler(signal, frame):
    sys.stderr.write('signalPIPE_handler!'+str(sys.exc_info())+'\n')
    return #sys.exit(0) # just return doesn't exit!
signal.signal(signal.SIGPIPE, signalPIPE_handler)

_old_excepthook = sys.excepthook
def myexcepthook(exctype, value, intraceback):
  import sys
  import traceback
  sys.stderr.write("myexcepthook\n")
  if exctype == IOError:
    sys.stderr.write(" IOError intraceback:\n")
    traceback.print_tb(intraceback)
  else:
    _old_excepthook(exctype, value, intraceback)
sys.excepthook = myexcepthook

def _trace(frame, event, arg):
  if event == 'exception':
    while frame is not None:
      filename, lineno = frame.f_code.co_filename, frame.f_lineno
      sys.stderr.write("_trace exc frame: " + filename \
        + " " + str(lineno) + " " + str(frame.f_trace) + str(arg) + "\n")
      if arg[0] == IOError:
        myexcepthook(arg[0], arg[1], arg[2])
      frame = frame.f_back
  return _trace
sys.settrace(_trace)

def exiter():
  import sys
  sys.stderr.write("Exiting\n")
atexit.register(exiter)

def main():
  teststr = "Hello " * 5
  try:
    sys.stdout.write(teststr + "\n")
    sys.stdout.flush()
  except IOError:
    sys.stderr.write("Exc: " + str(sys.exc_info()[0]) + "\n")
    #sys.exit(0)


if __name__ == "__main__":
  main()

Note the difference in how this script runs:

$ python2.7 testprint.py | echo

signalPIPE_handler!(None, None, None)
_trace exc frame: testprint.py 44 <function _trace at 0xb748e5dc>(<type 'exceptions.IOError'>, (32, 'Broken pipe'), <traceback object at 0xb748acac>)
myexcepthook
 IOError intraceback:
  File "testprint.py", line 44, in main
    sys.stdout.flush()
_trace exc frame: testprint.py 51 None(<type 'exceptions.IOError'>, (32, 'Broken pipe'), <traceback object at 0xb748acac>)
myexcepthook
 IOError intraceback:
  File "testprint.py", line 44, in main
    sys.stdout.flush()
Exc: <type 'exceptions.IOError'>
Exiting

$ python3.2 testprint.py | echo

signalPIPE_handler!(None, None, None)
_trace exc frame: testprint.py 44 <function _trace at 0xb74247ac>(<class 'IOError'>, (32, 'Broken pipe'), <traceback object at 0xb747393c>)
myexcepthook
 IOError intraceback:
  File "testprint.py", line 44, in main
    sys.stdout.flush()
_trace exc frame: testprint.py 51 None(<class 'IOError'>, (32, 'Broken pipe'), <traceback object at 0xb747393c>)
myexcepthook
 IOError intraceback:
  File "testprint.py", line 44, in main
    sys.stdout.flush()
Exc: <class 'IOError'>
signalPIPE_handler!(None, None, None)
Exiting
signalPIPE_handler!(None, None, None)
Exception IOError: (32, 'Broken pipe') in <_io.TextIOWrapper name='<stdout>' mode='w' encoding='UTF-8'> ignored

Note that signalPIPE_handler runs two times more in Python 3! I think, if there was some sort of "exception queue" in Python, I could "peek" in it, and remove remaining events in the signalPIPE_handler, so as to suppress the Exception ... ignored message... but I don't know of any such thing.

Finally, these resources are nice when trying to debug with gdb:

  • c - gdb - debugging with pipe - Stack Overflow
  • linux - Using gdb to single-step assembly code outside specified executable causes error "cannot find bounds of current function" - Stack Overflow

... since I don't have python3-dbg, all this reduces to stepping through machine instructions (layout asm in gdb, then Ctrl-X + A), which doesn't really tell me much. But here is how to trigger the problem in gdb:

In one terminal:

$ mkfifo foo 
$ gdb python3.2
...
Reading symbols from /usr/bin/python3.2...(no debugging symbols found)...done.
(gdb) run testprint.py > foo
Starting program: /usr/bin/python3.2 testprint.py > foo

Here it will block; in another terminal in the same diretory do:

$ echo <foo

... then return to first terminal - you should see:

...
Starting program: /usr/bin/python3.2 testprint.py > foo
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/i386-linux-gnu/libthread_db.so.1".

Program received signal SIGPIPE, Broken pipe.
0x0012e416 in __kernel_vsyscall ()
(gdb) bt
#0  0x0012e416 in __kernel_vsyscall ()
#1  0x0013c483 in __write_nocancel () from /lib/i386-linux-gnu/libpthread.so.0
#2  0x0815b549 in ?? ()
#3  0x08170507 in ?? ()
#4  0x08175e43 in PyObject_CallMethodObjArgs ()
#5  0x0815df21 in ?? ()
#6  0x0815f94e in ?? ()
#7  0x0815fb05 in ?? ()
#8  0x08170507 in ?? ()
#9  0x08175cb1 in _PyObject_CallMethod_SizeT ()
#10 0x08164851 in ?? ()
#11 0x080a3a36 in PyEval_EvalFrameEx ()
#12 0x080a3a53 in PyEval_EvalFrameEx ()
#13 0x080a43c8 in PyEval_EvalCodeEx ()
#14 0x080a466f in PyEval_EvalCode ()
#15 0x080c6e9d in PyRun_FileExFlags ()
#16 0x080c70c0 in PyRun_SimpleFileExFlags ()
#17 0x080db537 in Py_Main ()
#18 0x0805deee in main ()
(gdb) finish
Run till exit from #0  0x0012e416 in __kernel_vsyscall ()
0x0013c483 in __write_nocancel () from /lib/i386-linux-gnu/libpthread.so.0
...

Unfortunately, I don't have the possibility to build Python3 from source and debug it now; so I'll hope for an answer from someone who knows :)

Cheers!



回答2:

This error message is Python indicating that the supplied pipeline definition is broken, albeit in a somewhat confusing way (see http://bugs.python.org/issue11380)

echo doesn't actually accept input via stdin, so the input pipe from Python ends up being closed early. The extra exception you're seeing (outside the exception handler) is then due to the implicit attempt to flush the standard streams as the interpreter is shutting down. This happens outside the scope of any user provided Python code, so the interpreter just writes the error to stderr rather than invoking normal exception processing.

If you know you don't care about broken pipes for your use case, you can deal with this case by explicitly closing stdout before the end of your program. It will still complain about the broken pipe, but it will do it in a way that lets you catch and suppress the exception as usual:

import sys

def main():
  teststr = "Hello " * 5
  try:
    sys.stdout.write(teststr + "\n")
    sys.stdout.flush()
  except IOError:
    sys.stderr.write("Exc: " + str(sys.exc_info()[0]) + "\n")
  try:
    sys.stdout.close()
  except IOError:
    sys.stderr.write("Exc on close: " + str(sys.exc_info()[0]) + "\n")

if __name__ == "__main__":
  main()

In this version, only the expected output is seen, because even the attempt at closing it is enough to ensure the stream is already marked as closed during interpreter shutdown:

$ python3 testprint.py | echo

Exc: <class 'BrokenPipeError'>
Exc on close: <class 'BrokenPipeError'>


回答3:

This is a VERY ugly hack to suppress the error message from being shown in case printing to stdout caused a broken pipe (e.g. because a pager process invoked like your-program.py | less was quit without scrolling to the bottom of the output:

try:
    actual_code()
except BrokenPipeError:
    sys.stdout = os.fdopen(1)