Question about unreasonable slowness
 

[ Warning: I'm new to Python. Don't know it at all really yet, but had
to examine some 3rd party code because of performance problems with it.
]

Here's a code snippet:

i = 0
while (i < 20):
i = i + 1
(shellIn, shellOut) = os.popen4("/bin/sh -c ':'") # for testing, the
spawned shell does nothing
print 'next'
# for line in shellOut:
# print line

On my system (AIX 5.1 if it matters, with Python 2.4.3), this simple
loop spawning 20 subshells takes .75 sec. Ok, that's reasonable. Now,
if I uncomment the two commented lines, which loop over the empty
shellOut array, the progam now takes 11 secs. That slowdown seems
very hard to believe. Why should it slow down so much?

John.

Re: Question about unreasonable slowness
 

allenjo5@mail.northgrum.com wrote:
> i = 0
> while (i < 20):
> i = i + 1

for i in xrange(20):

> (shellIn, shellOut) = os.popen4("/bin/sh -c ':'") # for testing, the
> spawned shell does nothing
> print 'next'
> # for line in shellOut:
> # print line
>
> On my system (AIX 5.1 if it matters, with Python 2.4.3), this simple
> loop spawning 20 subshells takes .75 sec. Ok, that's reasonable. Now,
> if I uncomment the two commented lines, which loop over the empty
> shellOut array, the progam now takes 11 secs. That slowdown seems
> very hard to believe. Why should it slow down so much?

The key fact here is that shellOut isn't an array; it's a living,
breathing file object. If you don't iterate over it, you can run all 20
shell processes in parallel if necessary; but if you do iterate over it,
you're waiting for sh's stdout pipe to reach EOF, which effectively
means you can only run one process at a time.

On my system (OS X 10.4 with Python 2.5 installed), your code runs in
..187 secs with the loop commented out, and in .268 secs otherwise. But I
guess AIX's sh is slower than OS X's.

Re: Question about unreasonable slowness
 

allenjo5@mail.northgrum.com wrote:
> i = 0
> while (i < 20):
> i = i + 1

for i in xrange(20):

> (shellIn, shellOut) = os.popen4("/bin/sh -c ':'") # for testing, the
> spawned shell does nothing
> print 'next'
> # for line in shellOut:
> # print line
>
> On my system (AIX 5.1 if it matters, with Python 2.4.3), this simple
> loop spawning 20 subshells takes .75 sec. Ok, that's reasonable. Now,
> if I uncomment the two commented lines, which loop over the empty
> shellOut array, the progam now takes 11 secs. That slowdown seems
> very hard to believe. Why should it slow down so much?

The key fact here is that shellOut isn't an array; it's a living,
breathing file object. If you don't iterate over it, you can run all 20
shell processes in parallel if necessary; but if you do iterate over it,
you're waiting for sh's stdout pipe to reach EOF, which effectively
means you can only run one process at a time.

On my system (OS X 10.4 with Python 2.5 installed), your code runs in
..187 secs with the loop commented out, and in .268 secs otherwise. But I
guess AIX's sh is slower than OS X's.

Re: Question about unreasonable slowness
 

On Thu, 16 Nov 2006 12:45:18 -0800, allenjo5 wrote:

> [ Warning: I'm new to Python. Don't know it at all really yet, but had
> to examine some 3rd party code because of performance problems with it.
> ]
>
> Here's a code snippet:
>
> i = 0
> while (i < 20):
> i = i + 1


You probably want to change that to:

for i in range(20):

If 20 is just a place-holder, and the real value is much bigger, change
the range() to xrange().


> (shellIn, shellOut) = os.popen4("/bin/sh -c ':'") # for testing, the
> spawned shell does nothing
> print 'next'
> # for line in shellOut:
> # print line
>
> On my system (AIX 5.1 if it matters, with Python 2.4.3), this simple
> loop spawning 20 subshells takes .75 sec. Ok, that's reasonable. Now,
> if I uncomment the two commented lines, which loop over the empty
> shellOut array, the progam now takes 11 secs. That slowdown seems
> very hard to believe. Why should it slow down so much?

What are you using to time the code?

Replacing print statements with "pass", I get these results:

>>> import timeit
>>>
>>> def test():
.... i = 0
.... while (i < 20):
.... i = i + 1
.... (shellIn, shellOut) = os.popen4("/bin/sh -c ':'")
.... pass # print 'next'
.... for line in shellOut:
.... pass # print line
....
>>> timeit.Timer("test()", "from __main__ import test\nimport os").timeit(1)
0.49781703948974609
>>> timeit.Timer("test()", "from __main__ import test\nimport os").timeit(100)
54.894074201583862

About 0.5 second to open and dispose of 20 subshells, even with the "for
line in shellOut" loop.


I think you need some more fine-grained testing to determine whether the
slowdown is actually happening inside the "for line in shellOut" loop or
inside the while loop or when the while loop completes.



--
Steven.

Re: Question about unreasonable slowness
 

On 16 Nov 2006 12:45:18 -0800, allenjo5@mail.northgrum.com declaimed the
following in comp.lang.python:

> [ Warning: I'm new to Python. Don't know it at all really yet, but had
> to examine some 3rd party code because of performance problems with it.
> ]
>
No comment on your timing problem, but...

> Here's a code snippet:
>
> i = 0
> while (i < 20):
> i = i + 1

for i in xrange(20): #replaces all three of the above lines
--
Wulfraed Dennis Lee Bieber KD6MOG
wlfraed@ix.netcom.com wulfraed@bestiaria.com
HTTP://wlfraed.home.netcom.com/
(Bestiaria Support Staff: web-asst@bestiaria.com)
HTTP://www.bestiaria.com/

Re: Question about unreasonable slowness
 

Leif K-Brooks wrote:
> allenjo5@mail.northgrum.com wrote:
> > i = 0
> > while (i < 20):
> > i = i + 1
>
> for i in xrange(20):
>
> > (shellIn, shellOut) = os.popen4("/bin/sh -c ':'") # for testing, the
> > spawned shell does nothing
> > print 'next'
> > # for line in shellOut:
> > # print line
> >
> > On my system (AIX 5.1 if it matters, with Python 2.4.3), this simple
> > loop spawning 20 subshells takes .75 sec. Ok, that's reasonable. Now,
> > if I uncomment the two commented lines, which loop over the empty
> > shellOut array, the progam now takes 11 secs. That slowdown seems
> > very hard to believe. Why should it slow down so much?
>
> The key fact here is that shellOut isn't an array; it's a living,
> breathing file object. If you don't iterate over it, you can run all 20
> shell processes in parallel if necessary; but if you do iterate over it,
> you're waiting for sh's stdout pipe to reach EOF, which effectively
> means you can only run one process at a time.

Aha! I now notice that with the second loop commented out, I see many
python processes running for a little while after the main program
ends. So that confirms what you stated.

> On my system (OS X 10.4 with Python 2.5 installed), your code runs in
> .187 secs with the loop commented out, and in .268 secs otherwise. But I
> guess AIX's sh is slower than OS X's.

Ok, I built Python 2.5 (same AIX 5.1 machine). With the "for line in
shellOut" loop in, it now takes "only" 7 secs instead of the 11 secs in
python 2.4.3. So, that's better, but still unreasonably slow. And to
answer another's question, I'm using the ksh builtin 'time' command to
time the overall script.

BTW, I don't think the AIX /bin/sh (actually ksh) is inherently slow.
This naively translated pure shell version of my python test script
completes in .1 secs:

i=1
while ((i<20))
do ((i+=1))
print next
print "$shellIn" | /bin/sh -c ':' |
while read line
do print $line
done
done

Has anyone tried this on a true unix box (AIX, HPUX, Solaris, Linux)?
It seems to be functioning differently (and faster) on Windows and OS X
(though I guess at its heard, OS X is essentially unix).

John.

Re: Question about unreasonable slowness
 

allenjo5@mail.northgrum.com:
> Ok, I built Python 2.5 (same AIX 5.1 machine). With the "for line in
> shellOut" loop in, it now takes "only" 7 secs instead of the 11 secs in
> python 2.4.3. So, that's better, but still unreasonably slow. And to
> answer another's question, I'm using the ksh builtin 'time' command to
> time the overall script.
>
> BTW, I don't think the AIX /bin/sh (actually ksh) is inherently slow.
> This naively translated pure shell version of my python test script
> completes in .1 secs:
>
> i=1
> while ((i<20))
> do ((i+=1))
> print next
> print "$shellIn" | /bin/sh -c ':' |
> while read line
> do print $line
> done
> done
>
> Has anyone tried this on a true unix box (AIX, HPUX, Solaris, Linux)?
> It seems to be functioning differently (and faster) on Windows and OS X
> (though I guess at its heard, OS X is essentially unix).
>
> John.
>

Linux 2.6.17-1.2142_FC4smp #1 SMP Tue Jul 11 22:57:02 EDT 2006 i686 i686
i386 GNU/Linux

# <code>

import os
import timeit

def test():
for i in xrange(20):
(shellIn, shellOut) = os.popen4("/bin/sh -c ':'")
print 'next'
for line in shellOut:
print line

print timeit.Timer("test()", "from __main__ import test\nimport
os").timeit(1)

# </code>


This returns in 0.4 seconds. If I time it to do 50 tests, it returns
after 20.2 - 20.5 seconds. Even if I substitute the for i in xrange()
construct to your sh-like while statement. And all that through a
network, with print statements intact. Guess your true Unix box has some
features unavailable on Fedora Core or MacOS X ;-)

Regards,
Łukasz Langa

Re: Question about unreasonable slowness
 

Łukasz Langa wrote:
> allenjo5@mail.northgrum.com:
> > Ok, I built Python 2.5 (same AIX 5.1 machine). With the "for line in
> > shellOut" loop in, it now takes "only" 7 secs instead of the 11 secs in
> > python 2.4.3. So, that's better, but still unreasonably slow. And to
> > answer another's question, I'm using the ksh builtin 'time' command to
> > time the overall script.
> >
> > BTW, I don't think the AIX /bin/sh (actually ksh) is inherently slow.
> > This naively translated pure shell version of my python test script
> > completes in .1 secs:
> >
> > i=1
> > while ((i<20))
> > do ((i+=1))
> > print next
> > print "$shellIn" | /bin/sh -c ':' |
> > while read line
> > do print $line
> > done
> > done
> >
> > Has anyone tried this on a true unix box (AIX, HPUX, Solaris, Linux)?
> > It seems to be functioning differently (and faster) on Windows and OS X
> > (though I guess at its heard, OS X is essentially unix).
> >
> > John.
> >
>
> Linux 2.6.17-1.2142_FC4smp #1 SMP Tue Jul 11 22:57:02 EDT 2006 i686 i686
> i386 GNU/Linux
>
> # <code>
>
> import os
> import timeit
>
> def test():
> for i in xrange(20):
> (shellIn, shellOut) = os.popen4("/bin/sh -c ':'")
> print 'next'
> for line in shellOut:
> print line
>
> print timeit.Timer("test()", "from __main__ import test\nimport
> os").timeit(1)
>
> # </code>
>
>
> This returns in 0.4 seconds. If I time it to do 50 tests, it returns
> after 20.2 - 20.5 seconds. Even if I substitute the for i in xrange()
> construct to your sh-like while statement. And all that through a
> network, with print statements intact. Guess your true Unix box has some
> features unavailable on Fedora Core or MacOS X ;-)

Yeah, apparently this is an AIX specific issue - perhaps the python
implementation of popen4() needs to do something special for AIX?

I've since tested my script on SunOS 5.9 with Python 2.4.2, and it took
only about 1.5 sec with or without the second for loop, but without it,
there were no extra python processes running in the background when the
main one ends, unlike what I saw on AIX. This might be a clue to
someone who knows more than I do... any Python gurus out there runnin
AIX?

John.

Re: Question about unreasonable slowness
 

On Fri, 17 Nov 2006 12:39:16 -0800, allenjo5 wrote:

>> allenjo5@mail.northgrum.com:
>> > Ok, I built Python 2.5 (same AIX 5.1 machine). With the "for line in
>> > shellOut" loop in, it now takes "only" 7 secs instead of the 11 secs in
>> > python 2.4.3. So, that's better, but still unreasonably slow. And to
>> > answer another's question, I'm using the ksh builtin 'time' command to
>> > time the overall script.
>> >
>> > BTW, I don't think the AIX /bin/sh (actually ksh) is inherently slow.
>> > This naively translated pure shell version of my python test script
>> > completes in .1 secs:
>> >
>> > i=1
>> > while ((i<20))
>> > do ((i+=1))
>> > print next
>> > print "$shellIn" | /bin/sh -c ':' |
>> > while read line
>> > do print $line
>> > done
>> > done
>>
> Yeah, apparently this is an AIX specific issue - perhaps the python
> implementation of popen4() needs to do something special for AIX?

This seems likely a more general issue, rather than just a python issue
(although the huge speed up from moving to 2.5.x). A
couple of things I'd try:

1. Split the spawn/IO apart, twenty procs. should be fine.
2. Try making the pipe buffer size bigger (optional third argument to
os.popen4).
3. Note that you might well be spawning three processes, and
are definitely doing two shells. Any shell init. slowness is going to be
none fun. Use an array to run /bin/true, and time that.

--
James Antill -- james@and.org
http://www.and.org/and-httpd/ -- $2,000 security guarantee
http://www.and.org/vstr/

Re: Question about unreasonable slowness
 

James Antill wrote:
> On Fri, 17 Nov 2006 12:39:16 -0800, allenjo5 wrote:
>
> >> allenjo5@mail.northgrum.com:
> >> > Ok, I built Python 2.5 (same AIX 5.1 machine). With the "for line in
> >> > shellOut" loop in, it now takes "only" 7 secs instead of the 11 secs in
> >> > python 2.4.3. So, that's better, but still unreasonably slow. And to
> >> > answer another's question, I'm using the ksh builtin 'time' command to
> >> > time the overall script.
> >> >
> >> > BTW, I don't think the AIX /bin/sh (actually ksh) is inherently slow.
> >> > This naively translated pure shell version of my python test script
> >> > completes in .1 secs:
> >> >
> >> > i=1
> >> > while ((i<20))
> >> > do ((i+=1))
> >> > print next
> >> > print "$shellIn" | /bin/sh -c ':' |
> >> > while read line
> >> > do print $line
> >> > done
> >> > done
> >>
> > Yeah, apparently this is an AIX specific issue - perhaps the python
> > implementation of popen4() needs to do something special for AIX?
>
> This seems likely a more general issue, rather than just a python issue
> (although the huge speed up from moving to 2.5.x). A
> couple of things I'd try:

With help from c.u.aix, I've discovered the problem. Python (in
popen2.py) is attempting to close filedescriptors 3 through 32767
before running the /bin/sh. This is because os.sysconf('SC_OPEN_MAX')
is returning 32767. So far, it looks like SC_OPEN_MAX is being set
correctly to 4 in posixmodule.c, and indeed, os.sysconf_names seems to
also have SC_OPEN_MAX set to 4:

python -c 'import os; print os.sysconf_names'

....
'SC_XOPEN_XCU_VERSION': 109, 'SC_OPEN_MAX': 4, 'SC_PRIORITIZED_IO': 91,
....

In fact, none of the values that sysconf_names has set for the various
constants are being returned by os.sysconf(). For example, the 2
others I just listed:

$ ./python -c 'import os; print os.sysconf("SC_XOPEN_XCU_VERSION")'
4

$ ./python -c 'import os; print os.sysconf("SC_PRIORITIZED_IO")'
-1

This makes no sense to me... unless there is some memory alignment or
endian issue going on here?