python subprocess: order of output changes when using subprocess.PIPE
<p>When I write a python script called <code>outer.py</code> containing</p>

<pre><code>p = subprocess.Popen(['./inner.py'])
print('Called inner.py without options, waiting for process...')
p.wait()
print('Waited for inner.py without options')

p = subprocess.Popen(['./inner.py'], stdout=subprocess.PIPE)
print('Called inner.py with PIPE, communicating...')
b_out, b_err = p.communicate()
out = b_out.decode('utf8')
print('out is "{}"'.format(out))
</code></pre>

<p>And an <code>inner.py</code> containing</p>

<pre><code>print("inner: Echoing Hallo")
p = subprocess.Popen(['echo', 'hallo'])
print("inner: Waiting for Echo to finish...")
p.wait()
print("inner: Waited for Echo")
</code></pre>

<p>I get the following when calling <code>outer.py</code> from a terminal:</p>

<pre><code>Called inner.py without options, waiting for process...
inner: Echoing Hallo
inner: Waiting for Echo to finish...
hallo
inner: Waited for Echo
Waited for inner.py without options

Called inner.py with PIPE, communicating...
out is "hallo
inner: Echoing Hallo
inner: Waiting for Echo to finish...
inner: Waited for Echo
"
</code></pre>

<p>Why, when calling <code>inner.py</code> with <code>stdout=subprocess.PIPE</code>, does the "hallo" appear before the "inner: Echoing Hallo" in the captured output?</p>

<p>I would guess that, for some reason (related to pipes vs. ttys, see <a href="http://stackoverflow.com/questions/107705/disable-output-buffering/107717#comment24604506_107717">this comment</a>), the output of the <code>inner.py</code> Python process is unbuffered the first time you call it, and buffered the second time you call it.  The first time, with unbuffered output, you get the result in the expected order written to your tty.  The second time, with buffering, the output from the <code>echo</code> command gets flushed first (because <code>echo</code> runs and terminates), and then all of the output from the <code>inner.py</code> process shows up at once, when <code>python</code> terminates.  If you disable output buffering for <code>inner.py</code>, you should get the same output in both cases.</p>

<p>Disable output buffering by setting the <code>PYTHONUNBUFFERED</code> environment variable, or by calling python with the <code>-u</code> switch, or by explicitly calling <code>sys.stdout.flush()</code> after every <code>print</code> (or <code>print(...,  flush=True)</code> on Python 3).</p>

<p>The difference between the behaviour of pipes and ttys seems to be a <a href="https://www.turnkeylinux.org/blog/unix-buffering" rel="nofollow">general behaviour of <code>stdio</code></a>: output to ttys is line-buffered (so, in your code, which reads line by line, it will seem to be unbuffered), whereas output to pipes is buffered.</p>

python order pipe subprocess python-3.5