Anybody else see this issue? On Thu, Feb 10, 2011 at 10:37 AM, Yang Zhang <yanghates...@gmail.com> wrote: > On Thu, Feb 10, 2011 at 12:28 AM, Jean-Michel Pichavant > <jeanmic...@sequans.com> wrote: >> Yang Zhang wrote: >>> >>> On Wed, Feb 9, 2011 at 11:01 AM, MRAB <pyt...@mrabarnett.plus.com> wrote: >>> >>>> >>>> On 09/02/2011 01:59, Yang Zhang wrote: >>>> >>>>> >>>>> 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. >>>>> >>>>> Any ideas what's happening? Further down is some example output. >>>>> Thanks in advance. >>>>> >>>>> 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 >>>>> >>>>> >>>> >>>> I changed 'python' to the path of python.exe and 'stuckproc.py' to its >>>> full path and tried it with Python 2.7 on Windows XP Pro. It worked as >>>> expected. >>>> >>> >>> Good point - I didn't specify that I'm seeing this on Linux (Ubuntu >>> 10.04's Python 2.6). >>> >>> >> >> python test.py 0.000 0 starting >> 0.026 0 writing >> 0.026 0 closing >> 0.026 0 reading >> 0.029 .. 0 done reading >> 0.030 1 starting >> 0.038 1 writing >> 0.058 1 closing >> 0.058 1 reading >> 0.061 .. 1 done reading >> 5.026 0 done >> 5.061 1 done >> >> on debian lenny (Python 2.5) >> >> JM >> > > FWIW, this is consistently reproduce-able across all the Ubuntu 10.04s > I've tried. You may need to increase the message size so that it's > large enough for your system. > > -- > Yang Zhang > http://yz.mit.edu/ >
-- Yang Zhang http://yz.mit.edu/ -- http://mail.python.org/mailman/listinfo/python-list
