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

Groups > comp.lang.python > #76540 > unrolled thread

asyncio subprocess PIPE output lost

Started byyuzhichang <yuzhichang@gmail.com>
First post2014-08-19 00:39 -0700
Last post2014-08-20 10:00 +0100
Articles 4 — 3 participants

Back to article view | Back to comp.lang.python

Contents

  asyncio subprocess PIPE output lost yuzhichang <yuzhichang@gmail.com> - 2014-08-19 00:39 -0700
    Re: asyncio subprocess PIPE output lost Kushal Kumaran <kushal@locationd.net> - 2014-08-19 22:38 +0530
      Re: asyncio subprocess PIPE output lost yuzhichang <yuzhichang@gmail.com> - 2014-08-19 21:04 -0700
        Re: asyncio subprocess PIPE output lost Mark Lawrence <breamoreboy@yahoo.co.uk> - 2014-08-20 10:00 +0100

#76540 — asyncio subprocess PIPE output lost

Fromyuzhichang <yuzhichang@gmail.com>
Date2014-08-19 00:39 -0700
Subjectasyncio subprocess PIPE output lost
Message-ID<545114fa-ef61-487e-a707-ddcc9e94bcb9@googlegroups.com>
Hi all,
    I'm new to asyncio introduced by Python 3.4. I created two tasks each pings a host. I noticed some pieces of output will be lost(see "error: found icmp_seq gap"). If I changed to run only one task, this problem never occur.
    Do you have any idea?
    Thanks!
Zhichang

zhichyu@cto-team-6:~$ python3 asyn2.py
got line: b'PING tyr.global.tektronix.net (10.250.163.252) 56(84) bytes of data.\n'
got line: b'64 bytes from tyr.global.tektronix.net (10.250.163.252): icmp_seq=2 ttl=55 time=204 ms\n'
got line: b'PING babylon.rich.tek.com (10.250.155.123) 56(84) bytes of data.\n'
got line: b'64 bytes from babylon.rich.tek.com (10.250.155.123): icmp_seq=2 ttl=55 time=205 ms\n'
got line: b'64 bytes from babylon.rich.tek.com (10.250.155.123): icmp_seq=3 ttl=55 time=205 ms\n'
got line: b'64 bytes from tyr.global.tektronix.net (10.250.163.252): icmp_seq=3 ttl=55 time=205 ms\n'
got line: b'64 bytes from babylon.rich.tek.com (10.250.155.123): icmp_seq=4 ttl=55 time=196 ms\n'
got line: b'64 bytes from tyr.global.tektronix.net (10.250.163.252): icmp_seq=4 ttl=55 time=198 ms\n'
got line: b'64 bytes from tyr.global.tektronix.net (10.250.163.252): icmp_seq=5 ttl=55 time=181 ms\n'
got line: b'64 bytes from babylon.rich.tek.com (10.250.155.123): icmp_seq=5 ttl=55 time=182 ms\n'
got line: b'64 bytes from babylon.rich.tek.com (10.250.155.123): icmp_seq=6 ttl=55 time=180 ms\n'
got line: b'64 bytes from tyr.global.tektronix.net (10.250.163.252): icmp_seq=6 ttl=55 time=179 ms\n'
got line: b'64 bytes from babylon.rich.tek.com (10.250.155.123): icmp_seq=7 ttl=55 time=193 ms\n'
got line: b'64 bytes from tyr.global.tektronix.net (10.250.163.252): icmp_seq=7 ttl=55 time=196 ms\n'
got line: b'64 bytes from tyr.global.tektronix.net (10.250.163.252): icmp_seq=8 ttl=55 time=185 ms\n'
got line: b'64 bytes from babylon.rich.tek.com (10.250.155.123): icmp_seq=8 ttl=55 time=187 ms\n'
got line: b'64 bytes from babylon.rich.tek.com (10.250.155.123): icmp_seq=9 ttl=55 time=213 ms\n'
got line: b'64 bytes from tyr.global.tektronix.net (10.250.163.252): icmp_seq=9 ttl=55 time=211 ms\n'
got line: b'64 bytes from babylon.rich.tek.com (10.250.155.123): icmp_seq=10 ttl=55 time=192 ms\n'
got line: b'64 bytes from tyr.global.tektronix.net (10.250.163.252): icmp_seq=10 ttl=55 time=192 ms\n'
got line: b'64 bytes from tyr.global.tektronix.net (10.250.163.252): icmp_seq=11 ttl=55 time=210 ms\n'
got line: b'64 bytes from babylon.rich.tek.com (10.250.155.123): icmp_seq=12 ttl=55 time=210 ms\n'
error: found icmp_seq gap!

zhichyu@cto-team-6:~$ cat asyn2.py
#!/usr/bin/env python3.4

'''
refers to 
* http://stackoverflow.com/questions/375427/non-blocking-read-on-a-subprocess-pipe-in-python/20697159#20697159
* 18.5.3.5.1. Example: Parallel execution of tasks
'''
import asyncio
import sys
import signal
import time
import re
from asyncio.subprocess import PIPE
from contextlib import closing
from functools import partial

icmp_seq = re.compile(b'icmp_seq=(?P<seq>\d+)')

@asyncio.coroutine
def ping(*args, max_line_size=1<<20, timeout=None, loop=None):
    if loop is None:
        loop = asyncio.get_event_loop()
    with_timeout = partial(asyncio.wait_for, timeout=timeout, loop=loop)

    # start child process
    process = yield from asyncio.create_subprocess_exec(*args, stdout=PIPE, stderr=PIPE, limit=max_line_size, loop=loop)
    try:
        seq = 0
        begin = loop.time()
        while(True):
            # read line (sequence of bytes ending with b'\n') asynchronously
            #line = yield from with_timeout(process.stdout.readline())
            line = yield from process.stdout.readline()
            print("got line:", line)
            sys.stdout.flush()
            m = icmp_seq.search(line)
            if(m):
                seq2 = int(m.group('seq'))
                if(seq!=0 and seq2!=seq + 1):
                    loop.stop()
                    print('error: found icmp_seq gap!')
                    break
                seq = seq2
            now = loop.time()
            if(now - begin > 1000):
                break
    finally:
        '''
        process.kill()
        rc = yield from with_timeout(process.wait())
        '''
        process.send_signal(signal.SIGTERM)
        (stdoutdata, stderrdata) = yield from with_timeout(process.communicate())
        print("final stdout:", stdoutdata)
        print("final stderr:", stderrdata)
        rc =  process.returncode
    return rc

#NOTE: use ProactorEventLoop on Windows as shown in the previous example
with closing(asyncio.get_event_loop()) as loop:
    # Some lines will be lost if running multiple tasks. Why?
    task1 = asyncio.async(ping("ping", "tyr.global.tektronix.net", timeout=5, loop=loop))
    task2 = asyncio.async(ping("ping", "babylon.rich.tek.com", timeout=5, loop=loop))
    tasks = [task1, task2]
    rc = loop.run_until_complete(asyncio.wait(tasks))
sys.exit(rc)

[toc] | [next] | [standalone]

#76593

FromKushal Kumaran <kushal@locationd.net>
Date2014-08-19 22:38 +0530
Message-ID<mailman.13159.1408473559.18130.python-list@python.org>
In reply to#76540
On Tue, Aug 19, 2014 at 1:09 PM, yuzhichang <yuzhichang@gmail.com> wrote:
> Hi all,
>     I'm new to asyncio introduced by Python 3.4. I created two tasks each pings a host. I noticed some pieces of output will be lost(see "error: found icmp_seq gap"). If I changed to run only one task, this problem never occur.
>     Do you have any idea?
>     Thanks!
> Zhichang
>
> zhichyu@cto-team-6:~$ python3 asyn2.py
> got line: b'PING tyr.global.tektronix.net (10.250.163.252) 56(84) bytes of data.\n'
> got line: b'64 bytes from tyr.global.tektronix.net (10.250.163.252): icmp_seq=2 ttl=55 time=204 ms\n'
> got line: b'PING babylon.rich.tek.com (10.250.155.123) 56(84) bytes of data.\n'
> got line: b'64 bytes from babylon.rich.tek.com (10.250.155.123): icmp_seq=2 ttl=55 time=205 ms\n'
> got line: b'64 bytes from babylon.rich.tek.com (10.250.155.123): icmp_seq=3 ttl=55 time=205 ms\n'
> got line: b'64 bytes from tyr.global.tektronix.net (10.250.163.252): icmp_seq=3 ttl=55 time=205 ms\n'
> got line: b'64 bytes from babylon.rich.tek.com (10.250.155.123): icmp_seq=4 ttl=55 time=196 ms\n'
> got line: b'64 bytes from tyr.global.tektronix.net (10.250.163.252): icmp_seq=4 ttl=55 time=198 ms\n'
> got line: b'64 bytes from tyr.global.tektronix.net (10.250.163.252): icmp_seq=5 ttl=55 time=181 ms\n'
> got line: b'64 bytes from babylon.rich.tek.com (10.250.155.123): icmp_seq=5 ttl=55 time=182 ms\n'
> got line: b'64 bytes from babylon.rich.tek.com (10.250.155.123): icmp_seq=6 ttl=55 time=180 ms\n'
> got line: b'64 bytes from tyr.global.tektronix.net (10.250.163.252): icmp_seq=6 ttl=55 time=179 ms\n'
> got line: b'64 bytes from babylon.rich.tek.com (10.250.155.123): icmp_seq=7 ttl=55 time=193 ms\n'
> got line: b'64 bytes from tyr.global.tektronix.net (10.250.163.252): icmp_seq=7 ttl=55 time=196 ms\n'
> got line: b'64 bytes from tyr.global.tektronix.net (10.250.163.252): icmp_seq=8 ttl=55 time=185 ms\n'
> got line: b'64 bytes from babylon.rich.tek.com (10.250.155.123): icmp_seq=8 ttl=55 time=187 ms\n'
> got line: b'64 bytes from babylon.rich.tek.com (10.250.155.123): icmp_seq=9 ttl=55 time=213 ms\n'
> got line: b'64 bytes from tyr.global.tektronix.net (10.250.163.252): icmp_seq=9 ttl=55 time=211 ms\n'
> got line: b'64 bytes from babylon.rich.tek.com (10.250.155.123): icmp_seq=10 ttl=55 time=192 ms\n'
> got line: b'64 bytes from tyr.global.tektronix.net (10.250.163.252): icmp_seq=10 ttl=55 time=192 ms\n'
> got line: b'64 bytes from tyr.global.tektronix.net (10.250.163.252): icmp_seq=11 ttl=55 time=210 ms\n'
> got line: b'64 bytes from babylon.rich.tek.com (10.250.155.123): icmp_seq=12 ttl=55 time=210 ms\n'
> error: found icmp_seq gap!
>
> <snipped code>

Before looking for possible bugs in your code, the first thing to
check would be if you are actually missing ping replies, rather than
output from the ping command.  Try increasing the timeout (-W) for the
ping command.  If you're familiar with tools like tcpdump and
wireshark, you could use those to examine the network traffic and see
if replies are missing.

-- 
regards,
kushal

[toc] | [prev] | [next] | [standalone]

#76633

Fromyuzhichang <yuzhichang@gmail.com>
Date2014-08-19 21:04 -0700
Message-ID<7326e896-fba6-4530-bf37-b4dfda08c222@googlegroups.com>
In reply to#76593
On Wednesday, August 20, 2014 1:08:17 AM UTC+8, Kushal Kumaran wrote:
> On Tue, Aug 19, 2014 at 1:09 PM, yuzhichang <yuzhichang@gmail.com> wrote:
> 
> > Hi all,
> 
> >     I'm new to asyncio introduced by Python 3.4. I created two tasks each pings a host. I noticed some pieces of output will be lost(see "error: found icmp_seq gap"). If I changed to run only one task, this problem never occur.
> 
> >     Do you have any idea?
> 
> >     Thanks!
> 
> > Zhichang
> 
> >
> 
> > zhichyu@cto-team-6:~$ python3 asyn2.py
> 
> > got line: b'PING tyr.global.tektronix.net (10.250.163.252) 56(84) bytes of data.\n'
> 
> > got line: b'64 bytes from tyr.global.tektronix.net (10.250.163.252): icmp_seq=2 ttl=55 time=204 ms\n'
> 
> > got line: b'PING babylon.rich.tek.com (10.250.155.123) 56(84) bytes of data.\n'
> 
> > got line: b'64 bytes from babylon.rich.tek.com (10.250.155.123): icmp_seq=2 ttl=55 time=205 ms\n'
> 
> > got line: b'64 bytes from babylon.rich.tek.com (10.250.155.123): icmp_seq=3 ttl=55 time=205 ms\n'
> 
> > got line: b'64 bytes from tyr.global.tektronix.net (10.250.163.252): icmp_seq=3 ttl=55 time=205 ms\n'
> 
> > got line: b'64 bytes from babylon.rich.tek.com (10.250.155.123): icmp_seq=4 ttl=55 time=196 ms\n'
> 
> > got line: b'64 bytes from tyr.global.tektronix.net (10.250.163.252): icmp_seq=4 ttl=55 time=198 ms\n'
> 
> > got line: b'64 bytes from tyr.global.tektronix.net (10.250.163.252): icmp_seq=5 ttl=55 time=181 ms\n'
> 
> > got line: b'64 bytes from babylon.rich.tek.com (10.250.155.123): icmp_seq=5 ttl=55 time=182 ms\n'
> 
> > got line: b'64 bytes from babylon.rich.tek.com (10.250.155.123): icmp_seq=6 ttl=55 time=180 ms\n'
> 
> > got line: b'64 bytes from tyr.global.tektronix.net (10.250.163.252): icmp_seq=6 ttl=55 time=179 ms\n'
> 
> > got line: b'64 bytes from babylon.rich.tek.com (10.250.155.123): icmp_seq=7 ttl=55 time=193 ms\n'
> 
> > got line: b'64 bytes from tyr.global.tektronix.net (10.250.163.252): icmp_seq=7 ttl=55 time=196 ms\n'
> 
> > got line: b'64 bytes from tyr.global.tektronix.net (10.250.163.252): icmp_seq=8 ttl=55 time=185 ms\n'
> 
> > got line: b'64 bytes from babylon.rich.tek.com (10.250.155.123): icmp_seq=8 ttl=55 time=187 ms\n'
> 
> > got line: b'64 bytes from babylon.rich.tek.com (10.250.155.123): icmp_seq=9 ttl=55 time=213 ms\n'
> 
> > got line: b'64 bytes from tyr.global.tektronix.net (10.250.163.252): icmp_seq=9 ttl=55 time=211 ms\n'
> 
> > got line: b'64 bytes from babylon.rich.tek.com (10.250.155.123): icmp_seq=10 ttl=55 time=192 ms\n'
> 
> > got line: b'64 bytes from tyr.global.tektronix.net (10.250.163.252): icmp_seq=10 ttl=55 time=192 ms\n'
> 
> > got line: b'64 bytes from tyr.global.tektronix.net (10.250.163.252): icmp_seq=11 ttl=55 time=210 ms\n'
> 
> > got line: b'64 bytes from babylon.rich.tek.com (10.250.155.123): icmp_seq=12 ttl=55 time=210 ms\n'
> 
> > error: found icmp_seq gap!
> 
> >
> 
> > <snipped code>
> 
> 
> 
> Before looking for possible bugs in your code, the first thing to
> 
> check would be if you are actually missing ping replies, rather than
> 
> output from the ping command.  Try increasing the timeout (-W) for the
> 
> ping command.  If you're familiar with tools like tcpdump and
> 
> wireshark, you could use those to examine the network traffic and see
> 
> if replies are missing.
> 
> 
> 
> -- 
> 
> regards,
> 
> kushal


Hi kushal,
    Wireshark shows some replies are missing. Changing destinations to localhost in code also fix the "icmp_seq gap" error. I should be more careful on debug these things.
    Thanks for your help!
Zhichang

[toc] | [prev] | [next] | [standalone]

#76647

FromMark Lawrence <breamoreboy@yahoo.co.uk>
Date2014-08-20 10:00 +0100
Message-ID<mailman.13194.1408525505.18130.python-list@python.org>
In reply to#76633
On 20/08/2014 05:04, yuzhichang wrote:

Would you please access this list via 
https://mail.python.org/mailman/listinfo/python-list or read and action 
this https://wiki.python.org/moin/GoogleGroupsPython to prevent us 
seeing double line spacing and single line paragraphs, thanks.

-- 
My fellow Pythonistas, ask not what our language can do for you, ask
what you can do for our language.

Mark Lawrence

[toc] | [prev] | [standalone]

Back to top | Article view | comp.lang.python

csiph-web