[ python-Bugs-1010098 ] CPU usage shoots up with asyncore

[SourceForge.net]

Bugs item #1010098, was opened at 2004-08-16 15:54
Message generated for change (Comment added) made by arigo
You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=105470&aid=1010098&group_id=5470

Category: Python Library
Group: Python 2.4
>Status: Closed
>Resolution: Fixed
Priority: 7
Submitted By: Thomas (thomasabc)
Assigned to: A.M. Kuchling (akuchling)
Summary: CPU usage shoots up with asyncore

Initial Comment:
The CPU usage of a python application program using 
asyncore.py shoot up to 99% under Python 2.4a1. After 
a comparison, it was found out that the same program 
ran without such high CPU usage under Python 2.3.3

A simple couple of programs to narrow down the problem 
showed that a single loop() was accompanied by a large 
number of poll() with 2.4a1, whereas a single loop() had 
only 3 calls to poll() with 2.3.3.

Please let me know if there is anything else I can do for 
you to analyse. A couple of python scripts are attached 
in a zip file for you as below:

- Summary of the test scripts

With these scripts, the test attempts to identify what 
function calls are called that might explain the high CPU 
usage observed.

asyncore_test.py:
Taken from the Python Library Reference 11.24.2 
asynchat Example, the test program starts a server 
process to simulate client request process.

http_test.py:
This program simply establishes connection to the server 
and closes after 10 seconds.

- Procedure

1. Start asyncore_test.py
2. Start http_test.py
3. Stop asyncore_test.py


----------------------------------------------------------------------

>Comment By: Armin Rigo (arigo)
Date: 2004-09-27 17:55

Message:
Logged In: YES 
user_id=4771

Experimenting a bit, I found out that using asynchat.py from Python 2.3.3 in an otherwise CVS HEAD Python solves the problem.  The problem was introduced in this file in revision 1.22 by Raymond: "Use collection.deque() instead of a list for a FIFO queue."  <Insert random rambling against this kind of optimizations here>  The problem is at line 261:  "return self.list == []"  which is a correct way to check if a list is empty, but not if a deque is empty!

Fix checked in as asynchat.py:1.25.

The same bug doesn't seem to be present anywhere else.

A few usages of deques in the standard library seem unjustified: in shlex.py, items are only added or removed at the left.

----------------------------------------------------------------------

Comment By: Tim Peters (tim_one)
Date: 2004-08-21 23:01

Message:
Logged In: YES 
user_id=31435

I can confirm the primary symptom on WinXP.  For the 10 
seconds http_test.py runs, CPU is nailed to the wall under 
current CVS Python, but is a trickle under 2.3.4.

asyncore appears to be irrelevant.  "The problem" is that the 
socket associated with __main__.http_request_handler 
always comes back in the w set from select.select() under 
current Python, but the select times out under 2.3.4.

More detail:  under current Python, dumping some prints in 
asyncore.poll() delivers a huge number of repetitions of this 
info:

socket map is
{1940: <__main__.http_request_handler connected 
127.0.0.1:3455 at 0x9da800>,
 1948: <__main__.AsyncHTTPServer listening :40004 at 
0x9d7fa8>}
r, w, e passed in is [1940, 1948] [1940, 1948] [1940, 1948]
r, w, e returned is [], [1940], []

Under 2.3.4, there are only a few lines of output total -- 
select() doesn't believe the sockets passed to it are ready to 
read or ready to write.

So the difference is in socket behavior, or in how the layers 
around asyncore here are using sockets.

----------------------------------------------------------------------

Comment By: Thomas (thomasabc)
Date: 2004-08-20 10:05

Message:
Logged In: YES 
user_id=1104845

Sorry, just to let you know that you press Ctrl+C to stop the 
script above at Step 3 to get an output displayed as shown in 
the file asyncore_comparison.txt below.



----------------------------------------------------------------------

Comment By: Raymond Hettinger (rhettinger)
Date: 2004-08-19 17:29

Message:
Logged In: YES 
user_id=80475

Andrew, what this due to your updates or was Martin's loop
counter the cause?

----------------------------------------------------------------------

You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=105470&aid=1010098&group_id=5470