Broken pipe when using head to display only the first lines of history

[sqlalchemy-bot]

Migrated issue, originally created by Janne Vanhala (@jpvanhal)

I have hundreds of migrations in a project. I would like to list only the most recent ones. If I use head like this:

alembic history | head

Only the first 10 lines of alembic history are correctly printed, but then Alembic crashes with the following exception:

Traceback (most recent call last):
  File "/Users/janne/.virtualenvs/project/bin/alembic", line 9, in <module>
    load_entry_point('alembic==0.6.1', 'console_scripts', 'alembic')()
  File "/Users/janne/.virtualenvs/project/lib/python2.7/site-packages/alembic/config.py", line 298, in main
    CommandLine(prog=prog).main(argv=argv)
  File "/Users/janne/.virtualenvs/project/lib/python2.7/site-packages/alembic/config.py", line 293, in main
    self.run_cmd(cfg, options)
  File "/Users/janne/.virtualenvs/project/lib/python2.7/site-packages/alembic/config.py", line 279, in run_cmd
    **dict((k, getattr(options, k)) for k in kwarg)
  File "/Users/janne/.virtualenvs/project/lib/python2.7/site-packages/alembic/command.py", line 193, in history
    _display_history(config, script, base, head)
  File "/Users/janne/.virtualenvs/project/lib/python2.7/site-packages/alembic/command.py", line 171, in _display_history
    config.print_stdout(sc.log_entry)
  File "/Users/janne/.virtualenvs/project/lib/python2.7/site-packages/alembic/config.py", line 95, in print_stdout
    "\n"
  File "/Users/janne/.virtualenvs/project/lib/python2.7/site-packages/alembic/util.py", line 139, in write_outstream
    stream.write(t)
IOError: [Errno 32] Broken pipe

[sqlalchemy-bot]

Michael Bayer (@zzzeek) wrote:

somehow mine's not doing that (on OSX) - i can use head, tail, less, i don't get a stack trace. Maybe this has something to do with how the "head" command is behaving on your OS ?

[sqlalchemy-bot]

Janne Vanhala (@jpvanhal) wrote:

I'm on OSX (10.9.1) as well and I'm using head that comes with the OS. This doesn't happen with tail or less, only head.

[sqlalchemy-bot]

Derek Harland (@donkopotamus) wrote:

I've observed this issue before in other python projects. You can generally replicate it yourself directly with something like:

$ python -c 'for i in range(100000): print(i)' | head
0
1
2
3
4
5
6
7
8
9
Traceback (most recent call last):
  File "<string>", line 1, in <module>
BrokenPipeError: [Errno 32] Broken pipe
Exception BrokenPipeError: BrokenPipeError(32, 'Broken pipe') in <_io.TextIOWrapper name='<stdout>' mode='w' encoding='UTF-8'> ignored

NOTE: In Python 3.3 you'll get a BrokenPipeError, in versions prior its just a plain IOError

To cause it you basically need:

• python to write a large block of data to (a piped) stdout. It has to be enough to overflow the write buffer.
• the pipe reader to quit/die. As long as the writer has overflown the buffer on the block the reader was reading, then the writer will die with the above exception. (e.g. it won't die if you reduce that loop size).

It happens because pythons default signal handling is setup to handle a SIGPIPE by raising an exception (similar to the way it handles a SIGINT by raising KeyboardInterrupt).

Options for removing this annoyance:

• just wrap your output routines in a try: … catch IOError:

• flush stdout regularly … yuck … bad design

• alter the SIGPIPE handler

import signal
signal.signal(signal.SIGPIPE, signal.SIG_DFL)

eg

$ python -c 'import signal; signal.signal(signal.SIGPIPE, signal.SIG_DFL)
...> for i in range(100000): print(i)' | head
0
1
2
3
4
5
6
7
8
9

[sqlalchemy-bot]

Michael Bayer (@zzzeek) wrote:

ill just catch the IOError. we just put that around the stdout writing routine and we're done, right ?

[sqlalchemy-bot]

Derek Harland (@donkopotamus) wrote:

yep

[sqlalchemy-bot]

Changes by Michael Bayer (@zzzeek):

• added labels: command interface

[sqlalchemy-bot]

Changes by Michael Bayer (@zzzeek):

• set milestone to "tier 1"

[sqlalchemy-bot]

Michael Bayer (@zzzeek) wrote:

yup, easy to replicate with a command added like this:

diff --git a/alembic/command.py b/alembic/command.py
index f1c5962..a5386ff 100644
--- a/alembic/command.py
+++ b/alembic/command.py
@@ -264,3 +264,8 @@ def splice(config, parent, child):
 
     """
     raise NotImplementedError()
+
+
+def simulate_crap(config):
+    for i in range(10000):
+        print i
\ No newline at end of file

#!

$ python -m alembic.config simulate_crap | head
0
1
2
3
4
5
6
7
8
9
Traceback (most recent call last):
  File "/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/runpy.py", line 162, in _run_module_as_main
    "__main__", fname, loader, pkg_name)
  File "/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/runpy.py", line 72, in _run_code
    exec code in run_globals
  File "/Users/classic/dev/alembic/alembic/config.py", line 301, in <module>
    main()
  File "/Users/classic/dev/alembic/alembic/config.py", line 298, in main
    CommandLine(prog=prog).main(argv=argv)
  File "/Users/classic/dev/alembic/alembic/config.py", line 293, in main
    self.run_cmd(cfg, options)
  File "/Users/classic/dev/alembic/alembic/config.py", line 279, in run_cmd
    **dict((k, getattr(options, k)) for k in kwarg)
  File "alembic/command.py", line 271, in simulate_crap
    print i
IOError: [Errno 32] Broken pipe

[sqlalchemy-bot]

Michael Bayer (@zzzeek) wrote:

it doesnt seem to be preventable in Python 3, it comes out as a warning in _io.TextIOWrapper.

[sqlalchemy-bot]

Michael Bayer (@zzzeek) wrote:

unless we use the signal approach. But, that means, when "head" finishes reading output, the program terminates. Which I don't think we can do. If someone runs a long migration through "head" we don't except the program to silently not complete. I've verified this is the effect.

[sqlalchemy-bot]

Michael Bayer (@zzzeek) wrote:

• Suppressed IOErrors which can raise when program output pipe
  is closed under a program like head; however this only
  works on Python 2. On Python 3, there is not yet a known way to
  suppress the BrokenPipeError warnings without prematurely terminating
  the program via signals. fixes Broken pipe when using head to display only the first lines of history #160.
  Added comments to http://bugs.python.org/issue11380 to see what the
  status is on py3k.

→ f889070

[sqlalchemy-bot]

Changes by Michael Bayer (@zzzeek):

• changed status to closed

[sqlalchemy-bot]

Florent Xicluna (@flox) wrote:

I tried to reproduce the issue on Python3 with the sample code on one of the previous comment. No success.
https://bitbucket.org/zzzeek/alembic/issue/160/broken-pipe-when-using-head-to-display#comment-8068721

On Debian with Python 3.2.5, 3.3.5 and 3.4.0

$ python3.2 -c 'for i in range(100000): print(i)' | head -2
0
1
Traceback (most recent call last):
  File "<string>", line 1, in <module>
IOError: [Errno 32] Broken pipe

$ python3.3 -c 'for i in range(100000): print(i)' | head -2                                           
0
1
Traceback (most recent call last):
  File "<string>", line 1, in <module>
BrokenPipeError: [Errno 32] Broken pipe

$ python3.4 -c 'for i in range(100000): print(i)' | head -2
0
1
Traceback (most recent call last):
  File "<string>", line 1, in <module>
BrokenPipeError: [Errno 32] Broken pipe

$ 

I never got the uncatchable message

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

[sqlalchemy-bot]

Michael Bayer (@zzzeek) wrote:

script:

import sys

def simulate_crap(stream):
    for i in range(10000):
        stream.write("%d\n" % i)

try:
    simulate_crap(sys.stdout)
except IOError:
    pass

Py2K:

#!

classic$ python test.py | head
0
1
2
3
4
5
6
7
8
9
classics-MacBook-Pro-2:alembic classic$ 

Py3K:

#!

$ python3 test.py | head
0
1
2
3
4
5
6
7
8
9
Exception ignored in: <_io.TextIOWrapper name='<stdout>' mode='w' encoding='US-ASCII'>
BrokenPipeError: [Errno 32] Broken pipe

[sqlalchemy-bot]

Florent Xicluna (@flox) wrote:

I tried exactly the above, and i had the same output for Python 3.2.5, 3.3.5 and 3.4.0 : no message "Exception ignored" at the end.

So I guess this is something specific to OS X.
(or the minor version differs)

[sqlalchemy-bot]

Michael Bayer (@zzzeek) wrote:

seems like

[sqlalchemy-bot]

Changes by Michael Bayer (@zzzeek):

• removed milestone (was: "tier 1")

[sqlalchemy-bot]

Derek Harland (@donkopotamus) wrote:

To suppress the BrokenPipe warning on OSX, what about the following:

import sys

def simulate_crap(stream):
    for i in range(10000):
        stream.write("%d\n" % i)

try:
    simulate_crap(sys.stdout)
except IOError:
    # assume that stdout has been closed at the other end rendering it unusable
    sys.stdout = None

With python 3.3 on OSX this will produce

$ python blah.py | head
0
1
2
3
4
5
6
7
8
9

[sqlalchemy-bot]

Frazer McLean (@RazerM) wrote:

Cam config.py be changed to the following, so that it is also fixed on Python 3? (from http://bugs.python.org/issue11380,#msg248579)

if __name__ == '__main__':
    try:
        main()
    finally:
        try:
            sys.stdout.flush()
        finally:
            try:
                sys.stdout.close()
            finally:
                try:
                    sys.stderr.flush()
                finally:
                    sys.stderr.close()

[sqlalchemy-bot]

Michael Bayer (@zzzeek) wrote:

@RazerM that workaround looks insane. does that prevent the warning we're getting in py3k? how is python itself not fixing that, it's awful? provide a pull request please where that would go? thanks

[sqlalchemy-bot]

Frazer McLean (@RazerM) wrote:

Yes, it prevents the warning. I'll provide a PR

[sqlalchemy-bot]

Michael Bayer (@zzzeek) wrote:

Ok. I'm going to try to work all the ugly into a context manager or something from your PR

[sqlalchemy-bot]

Michael Bayer (@zzzeek) wrote:

@RazerM can I please see the OS in use, Python version, stack trace, and commands to reproduce? The current approach of a simple IOError catch resolves the issue for me, and also note that rcollins' snippet on the Python bug is not an "official" workaround, it's conjectural for my specific case (but I cannot reproduce as long as IOError catch is there).

script:

import sys
from alembic.util.messaging import write_outstream


def simulate_crap(stream):
    for i in range(10000):
        write_outstream(stream, "%d\n" % i)

simulate_crap(sys.stdout)

running with both Python3.5, python3.6, piping into "head", "echo", etc., no error:

#!

[classic@photon2 alembic]$ .tox/py36/bin/python test.py  | head
0
1
2
3
4
5
6
7
8
9
[classic@photon2 alembic]$ .tox/py36/bin/python test.py  | head -20
0
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
[classic@photon2 alembic]$ .tox/py35/bin/python test.py  | echo

[classic@photon2 alembic]$ .tox/py35/bin/python test.py  | head
0
1
2
3
4
5
6
7
8
9

If I remove the existing IOError catch, error is immediate:

[classic@photon2 alembic]$ .tox/py35/bin/python test.py  | echo

Traceback (most recent call last):
  File "test.py", line 9, in <module>
    simulate_crap(sys.stdout)
  File "test.py", line 7, in simulate_crap
    write_outstream(stream, "%d\n" % i)
  File "/home/classic/dev/alembic/alembic/util/messaging.py", line 36, in write_outstream
    stream.write(t)
BrokenPipeError: [Errno 32] Broken pipe

Also tried with keyboard interrupts, no issue there either.

[sqlalchemy-bot]

Frazer McLean (@RazerM) wrote:

macOS 10.12.6

Using Python 3 installed by homebrew or pyenv I see this:

$ python3 test.py | echo

Exception ignored in: <_io.TextIOWrapper name='<stdout>' mode='w' encoding='UTF-8'>
BrokenPipeError: [Errno 32] Broken pipe
frazer@Atreus› ~/D/S/Python $

The reason is that the flush is being deferred until a __del__, and that's what prints the exception.

[sqlalchemy-bot]

Michael Bayer (@zzzeek) wrote:

so the main thing I want to figure out is if I can just put stdout.flush() in write_outstream and have it be local to each time we write things. can you try this patch?

diff --git a/alembic/util/messaging.py b/alembic/util/messaging.py
index c202e96..a944617 100644
--- a/alembic/util/messaging.py
+++ b/alembic/util/messaging.py
@@ -28,17 +28,20 @@ except (ImportError, IOError):
 
 def write_outstream(stream, *text):
     encoding = getattr(stream, 'encoding', 'ascii') or 'ascii'
-    for t in text:
-        if not isinstance(t, binary_type):
-            t = t.encode(encoding, 'replace')
-        t = t.decode(encoding)
+    try:
+        for t in text:
+            if not isinstance(t, binary_type):
+                t = t.encode(encoding, 'replace')
+            t = t.decode(encoding)
+            try:
+                stream.write(t)
+            except IOError:
+                break
+    finally:
         try:
-            stream.write(t)
+            stream.flush()
         except IOError:
-            # suppress "broken pipe" errors.
-            # no known way to handle this on Python 3 however
-            # as the exception is "ignored" (noisily) in TextIOWrapper.
-            break
+            pass
 
 
 def status(_statmsg, fn, *arg, **kw):

[sqlalchemy-bot]

Frazer McLean (@RazerM) wrote:

The patch doesn't fix it.

[sqlalchemy-bot]

Michael Bayer (@zzzeek) wrote:

but the stream is flushed every time and there's a catch around it. how?

[sqlalchemy-bot]

Derek Harland (@donkopotamus) wrote:

Just to repeat something from earlier in this thread. Does this not work?

import sys

def simulate_crap(stream):
    for i in range(10000):
        stream.write("%d\n" % i)

try:
    simulate_crap(sys.stdout)
except IOError:
    # assume that stdout has been closed at the other end rendering it unusable
    sys.stdout = None

With python 3.5 on OSX this produces:

$ python blah.py | head -2
0
1

[sqlalchemy-bot]

Michael Bayer (@zzzeek) wrote:

I'm mostly looking to make the workarounds here local to the inside of the write_outstream() method. putting a block around the "main()" of the program I find bothersome. Will do it if we really have to.