[New-bugs-announce] [issue11226] subprocesses experience mysterious delay in receiving stdin EOF

Yang Zhang report at bugs.python.org
Thu Feb 17 00:04:12 CET 2011


New submission from Yang Zhang <yang.pythonbugs at mailnull.com>:

I'm seeing this issue on all the multiple Ubuntu 10.04 boxes I've tried.

I reduced a problem I was seeing in my application down into the following test case. In this code, a parent process concurrently spawns 2 (you can spawn more) subprocesses that read a big message from the parent over stdin, sleep for 5 seconds, and write something back. However, there's unexpected waiting happening somewhere, causing the code to complete in 10 seconds instead of the expected 5.

If you set verbose=True, you can see that the straggling subprocess is receiving most of the messages, then waiting for the last chunk of 3 chars---it's not detecting that the pipe has been closed. Furthermore, if I simply don't do anything with the second process (doreturn=True), the first process will never see the EOF.

Further down is some example output. When trying this out, you may need to increase the message size to see the behavior occur.

from subprocess import *
from threading import *
from time import *
from traceback import *
import sys
verbose = False
doreturn = False
msg = (20*4096+3)*'a'
def elapsed(): return '%7.3f' % (time() - start)
if sys.argv[1:]:
  start = float(sys.argv[2])
  if verbose:
    for chunk in iter(lambda: sys.stdin.read(4096), ''):
      print >> sys.stderr, '..', time(), sys.argv[1], 'read', len(chunk)
  else:
    sys.stdin.read()
  print >> sys.stderr, elapsed(), '..', sys.argv[1], 'done reading'
  sleep(5)
  print msg
else:
  start = time()
  def go(i):
    print elapsed(), i, 'starting'
    p = Popen(['python','stuckproc.py',str(i), str(start)], stdin=PIPE, stdout=PIPE)
    if doreturn and i == 1: return
    print elapsed(), i, 'writing'
    p.stdin.write(msg)
    print elapsed(), i, 'closing'
    p.stdin.close()
    print elapsed(), i, 'reading'
    p.stdout.read()
    print elapsed(), i, 'done'
  ts = [Thread(target=go, args=(i,)) for i in xrange(2)]
  for t in ts: t.start()
  for t in ts: t.join()

Example output:

  0.001 0 starting
  0.003 1 starting
  0.005 0 writing
  0.016 1 writing
  0.093 0 closing
  0.093 0 reading
  0.094 1 closing
  0.094 1 reading
  0.098 .. 1 done reading
  5.103 1 done
  5.108 .. 0 done reading
 10.113 0 done

----------
components: Library (Lib)
messages: 128699
nosy: yaaang
priority: normal
severity: normal
status: open
title: subprocesses experience mysterious delay in receiving stdin EOF
type: behavior
versions: Python 2.6

_______________________________________
Python tracker <report at bugs.python.org>
<http://bugs.python.org/issue11226>
_______________________________________


More information about the New-bugs-announce mailing list