Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]


Groups > comp.lang.python > #55770

Re: Python subprocesses experience mysterious delay in receiving stdin EOF

Path csiph.com!eeepc.pasdenom.info!news.pasdenom.info!news.dougwise.org!aioe.org!feeder.news-service.com!news2.euro.net!newsgate.cistron.nl!newsgate.news.xs4all.nl!post.news.xs4all.nl!not-for-mail
Return-Path <prvs=0144e99ea=jeanmichel@sequans.com>
X-Original-To python-list@python.org
Delivered-To python-list@mail.python.org
X-Spam-Status OK 0.000
X-Spam-Evidence '*H*': 1.00; '*S*': 0.00; 'else:': 0.03; 'sys': 0.04; 'subject:Python': 0.05; '(python': 0.05; 'skip:` 10': 0.05; 'wed,': 0.05; 'chunk': 0.07; 'concurrently': 0.07; 'debian': 0.07; 'unexpected': 0.07; 'python': 0.08; 'advance.': 0.08; 'closed.': 0.09; 'sleep': 0.09; 'spawn': 0.09; 'subprocess': 0.09; 'seconds': 0.10; '>>>': 0.11; 'am,': 0.13; 'wrote:': 0.14; 'def': 0.14; 'linux': 0.14; 'case.': 0.15; 'traceback': 0.15; '(ubuntu': 0.16; '*never*': 0.16; '0.001': 0.16; '0.093': 0.16; '2.5)': 0.16; 'expected.': 0.16; 'more)': 0.16; 'mrab': 0.16; 'received:192.168.200': 0.16; 'seconds,': 0.16; 'stdin,': 0.16; 'subject:EOF': 0.16; 'subject:delay': 0.16; 'subject:stdin': 0.16; 't.join()': 0.16; 't.start()': 0.16; 'threading': 0.16; 'feb': 0.16; 'cc:no real name:2**0': 0.17; '2.7': 0.18; 'cc:2**0': 0.21; 'code,': 0.21; 'tried': 0.22; 'header:In-Reply-To:1': 0.23; 'cc:addr:python-list': 0.24; 'specify': 0.24; 'worked': 0.24; "didn't": 0.25; 'code': 0.25; 'closing': 0.27; 'second': 0.27; 'windows': 0.28; "i'm": 0.28; 'instead': 0.28; 'problem': 0.28; 'happening': 0.28; "what's": 0.29; 'example': 0.29; 'thanks': 0.30; 'parent': 0.30; 'seeing': 0.30; "skip:' 10": 0.30; 'cc:addr:python.org': 0.30; 'skip:[ 10': 0.31; 'changed': 0.31; 'import': 0.31; 'starting': 0.31; 'however,': 0.32; 'skip:p 30': 0.33; 'causing': 0.33; 'received:192': 0.34; 'header:User- Agent:1': 0.34; 'done': 0.35; 'print': 0.35; 'point': 0.35; 'anything': 0.36; 'test': 0.37; 'received:192.168': 0.37; 'set': 0.37; 'back.': 0.37; 'skip:s 20': 0.38; 'ideas': 0.38; 'subject:: ': 0.39; 'expected': 0.39; 'some': 0.39; 'full': 0.61; 'further': 0.61; 'waiting': 0.64; '0.000': 0.84; 'start)': 0.84; 'subject:experience': 0.84; 'zhang': 0.84
X-IronPort-AV E=Sophos;i="4.60,446,1291590000"; d="scan'208";a="980773"
X-Virus-Scanned amavisd-new at zimbra.sequans.com
Date Wed, 09 Feb 2011 17:28:55 +0100
From Jean-Michel Pichavant <jeanmichel@sequans.com>
User-Agent Mozilla-Thunderbird 2.0.0.24 (X11/20100328)
MIME-Version 1.0
To Yang Zhang <yanghatespam@gmail.com>
Subject Re: Python subprocesses experience mysterious delay in receiving stdin EOF
References <AANLkTi=D7ySVTesrf2+TBddaNDF=E616ACVeUm5OSwcC@mail.gmail.com> <4D52037E.4000809@mrabarnett.plus.com> <AANLkTik+kydEJGy1-M3BbwJczxTyA91r3YW0xfWsuko2@mail.gmail.com>
In-Reply-To <AANLkTik+kydEJGy1-M3BbwJczxTyA91r3YW0xfWsuko2@mail.gmail.com>
Content-Type text/plain; charset=ISO-8859-1; format=flowed
Content-Transfer-Encoding 7bit
Cc python-list@python.org
X-BeenThere python-list@python.org
X-Mailman-Version 2.1.12
Precedence list
List-Id General discussion list for the Python programming language <python-list.python.org>
List-Unsubscribe <http://mail.python.org/mailman/options/python-list>, <mailto:python-list-request@python.org?subject=unsubscribe>
List-Archive <http://mail.python.org/pipermail/python-list>
List-Post <mailto:python-list@python.org>
List-Help <mailto:python-list-request@python.org?subject=help>
List-Subscribe <http://mail.python.org/mailman/listinfo/python-list>, <mailto:python-list-request@python.org?subject=subscribe>
Newsgroups comp.lang.python
Message-ID <mailman.46.1297268936.1633.python-list@python.org> (permalink)
Lines 101
NNTP-Posting-Host 82.94.164.166
X-Trace 1297268936 news.xs4all.nl 41114 [::ffff:82.94.164.166]:45046
X-Complaints-To abuse@xs4all.nl
Xref csiph.com comp.lang.python:55770

Show key headers only | View raw


Yang Zhang wrote:
> On Wed, Feb 9, 2011 at 11:01 AM, MRAB <python@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

Back to comp.lang.python | Previous | Next | Find similar | Unroll thread


Thread

Re: Python subprocesses experience mysterious delay in receiving stdin EOF Jean-Michel Pichavant <jeanmichel@sequans.com> - 2011-02-09 17:28 +0100

csiph-web