Repository navigation
Neverending warnings from asyncore #41680
Description
| BPO | 1161031 |
|---|---|
| Nosy | @tim-one, @akuchling, @gpshead, @josiahcarlson, @giampaolo, @devdanzin, @alexer |
| Files |
Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.
Show more details
GitHub fields:
assignee = 'https://github.com/josiahcarlson'
closed_at = <Date 2009-03-31.19:34:33.562>
created_at = <Date 2005-03-11.00:34:47.000>
labels = ['type-bug', 'library']
title = 'Neverending warnings from asyncore'
updated_at = <Date 2009-04-01.15:27:07.650>
user = 'https://bugs.python.org/anadelonbrin'bugs.python.org fields:
activity = <Date 2009-04-01.15:27:07.650>
actor = 'brett.cannon'
assignee = 'josiahcarlson'
closed = True
closed_date = <Date 2009-03-31.19:34:33.562>
closer = 'josiahcarlson'
components = ['Library (Lib)']
creation = <Date 2005-03-11.00:34:47.000>
creator = 'anadelonbrin'
dependencies = []
files = ['13513', '13517']
hgrepos = []
issue_num = 1161031
keywords = ['patch']
message_count = 28.0
messages = ['24529', '24530', '24531', '24532', '24533', '24534', '24535', '24536', '24537', '24538', '24539', '81703', '81722', '81731', '81732', '84769', '84773', '84779', '84797', '84826', '84839', '84850', '84855', '84879', '84892', '84893', '84928', '84936']
nosy_count = 8.0
nosy_names = ['tim.peters', 'akuchling', 'gregory.p.smith', 'anadelonbrin', 'josiahcarlson', 'giampaolo.rodola', 'ajaksu2', 'alexer']
pr_nums = []
priority = 'normal'
resolution = 'accepted'
stage = 'test needed'
status = 'closed'
superseder = None
type = 'behavior'
url = 'https://bugs.python.org/issue1161031'
versions = ['Python 2.7']
Activity
anadelonbrin commentedon Mar 11, 2005
Changes in asyncore from 2.3 to 2.4 mean that
asyncore.poll() now passes all the sockets in the map
to select.select() to be checked for errors, which is
probably a good thing. If an error occurs, then
handle_expt() is called, which by default logs the error.
asyncore.dispatcher creates nonblocking sockets. When
connect_ex() is called on a nonblocking socket, it will
probably return EWOULDBLOCK (connecting takes time),
which may mean the connection is successful, or may not
(asyncore dispatcher keeps going assuming all is well).
If the connection is not successful, and then
asyncore.loop() is called, then select.select() will
indicate that there is an error with the socket (can't
connect) and the error will be logged.
The trouble is that asyncore.loop then keeps going, and
will log this error again. My not-that-fast system
here gets about 10,000 logged messages per second with
a single socket in the asyncore map.
There are ways to avoid this:
(1) if the socket is blocking when connect()ing (and
then nonblocking afterwards) an error is raised if the
connect fails.
(2) Before calling asyncore.loop(), the caller can
run through all the sockets, checking that they are ok.
(3) handle_expt() can be overridden with a function
that repairs or removes the socket from the map (etc)
However, I'm not convinced that this is good behavior
for asyncore to have, by default. On Windows,
select.select() will only indicate an error when trying
to connect (nonblocking) or if SO_OOBINLINE is
disabled, but this may not be the case (i.e. errors can
occur at other times) with other platforms, right?
Unless the error is temporary, asyncore will by default
start streaming (extremely fast) a lot of "warning:
unhandled exception" (not very helpful an error
message, either) messages. Even if the error only
lasts a minute, that could easily result in 10,000
warnings being logged.
Do any of the python developers agree that this is a
flaw? I'm happy to work up a patch for whatever the
desired solution is, if so.
josiahcarlson commentedon May 31, 2005
Logged In: YES
user_id=341410
Option 1 is not really an option in any case where a large
number of connections are opened (so I don't believe should
be the default).
From what I understand, certain methods are supposed to be
overridden in a subclass if someone using a class wants
different behavior.
In this case, I believe you can perform either option 2 or 3
in your own code to avoid the thousands of logged lines;
either by creating your own loop() function, or by creating
a subclass of dispatcher and implementing a handle_expt()
method that does as you desire.
anadelonbrin commentedon May 31, 2005
Logged In: YES
user_id=552329
Yes this problem is easily solved by subclassing. However I
firmly believe that it is a terrible default behaviour, and that it's
likely to hit many asyncore users. A class shouldn't have to
be subclassed to be usable (ignoring virtual classes and all
that), and that really is the case here.
The simplest solution would be to change the handler to not
log the message. Or log the message once per socket or
something.
josiahcarlson commentedon May 31, 2005
Logged In: YES
user_id=341410
I hate to point out the obvious, but dispatcher is wholly
unusable without subclassing. How would you get data
to/from a connection without replacing handle_read,
handle_write? How do you handle the case when you want to
connect to someone else or accept connections from someone
else without overloading handle_connect or handle_accept?
anadelonbrin commentedon May 31, 2005
Logged In: YES
user_id=552329
dispatcher is not at all unusable without subclassing. You
can get data with recv() and send it with send() etc. It can be
treated as a thin wrapper around socket objects. Yes, you
will want to subclass it to get more useful behaviour than you
can get from a basic socket. I don't see that this means that
you should be required to override the handle_expt() function,
though. As much as possible a class should provide
sensible methods, so that overriding is kept to a minimum.
At the very least, this is a documentation error, since the
documentation states:
"""
handle_expt( )
Called when there is out of band (OOB) data for a socket
connection. This will almost never happen, as OOB is
tenuously supported and rarely used.
"""
"Almost never" is completely wrong.
josiahcarlson commentedon May 31, 2005
Logged In: YES
user_id=341410
You seem to be unwilling to subclass asyncore.dispatcher to
extend its functionality, and the only reason you have given
as to why you are unwilling is "As much as possible a class
should provide sensible methods, so that overriding is kept
to a minimum." (I personally subclass dispatcher and its
async_chat derivative qutie often)
Now, in the case of the other standard socket server and
client framework in the Python standard library, namely the
SocketServer module and its derivatives, you will find
extending the functionality of those classes is via
subclassing and overriding methods as necessary.
To me, when two 'competing' methods of generating socket
servers and clients in the standard library offer the same
method of extension of their base functionality, then
perhaps that is what should be done. The fact that
basically all of the standard library is subclassable (some
C modules are exceptions to the rule, but should be fixed in
Python 2.5), including types in the base language, further
suggests to me that subclassing is the standard mechanism
for extending the functionality of a class, regardless of
its usefulness in its base state.
In regards to the documentation, it seems to be that
whenever an object has an error, the handle_expt() method is
called (in spending two minutes reading the source).
Whether or not those errors are rare, perhaps debatable
(I've not seen any in years), but it seems to be
application-specific as to what behavior the socket should
have in the case of an error (you may want to close, I may
want to report the error and reconnect, etc.).
anadelonbrin commentedon Jun 3, 2005
Logged In: YES
user_id=552329
I am not at all unwilling (and this isn't a problem for me
personally - the issue here is whether this is good for
Python in general) to subclass. Deciding to subclass does
*not* mean that you should have to replace all functions in
the parent class. If you did, then there would be little
point in subclassing at all. Sensible default behaviour
should be provided as methods of classes. The current
behaviour of the handle_expt() method is not sensible. It
essentially forces the user to override that method, even if
they have no interest in handling errors (e.g. and would
normally just override handle_read and handle_write).
This is *not* rare. You haven't seen any in years, because
this was a change introduced in Python 2.4, which hasn't
been released for even one year yet. I agree that the
desired behaviour will be application specific. But what is
the point of having default behaviour that will essentially
crash the program/system running it? Having default
behaviour be "pass" would be more useful. At the very
least, this is a problem that many people (compared to the
number that will use asyncore) will come across and should
be reflected as such in the documentation.
If you haven't replicated this problem on your system so
that you understand it, please do. I am happy to provide a
simple script to demonstrate, if necessary.
tim-one commentedon Jun 3, 2005
Logged In: YES
user_id=31435
I agree the change in default behavior here was at least
questionable, and spent more than a week of my
own "dealing with consequences" of 2.4 asyncore changes in
ZODB and Zope.
Assigning to Andrew, since it looks like he made the change
in question here. Andrew, why did this change? How can it
be improved?
I don't think Tony has mentioned it here, but when
SpamBayes was first released with Python 2.4, it was a
disaster because some users found their hard drives literally
filled with gigabytes of mysterious "warning: unhandled
exception" messages.
akuchling commentedon Jun 9, 2005
Logged In: YES
user_id=11375
What change to asyncore caused the problem?
tim-one commentedon Jun 9, 2005
Logged In: YES
user_id=31435
My guess is rev 1.57.
josiahcarlson commentedon Jan 6, 2007
Can I get any pointers as to a conversion from CVS to SVN version numbers, or does anyone remember which change is the issue?
11 remaining items
giampaolo commentedon Mar 31, 2009
@aleksy
http://bugs.python.org/issue4501
alexer commentedon Mar 31, 2009
Sorry for the noise.
I just registered, and started going through the open issues for
asyncore in order. I'll read them all through before commenting on the
next one..
I also bumped to this:
http://groups.google.com/group/python-dev2/browse_thread/thread/eec1ddadefe09fd8/a38270231620870e?lnk=gst&q=asyncore
It seems lots of things i have been thinking about have already been
done, but the whole asyncore is at a standstill. Any pointers on where i
should look if i want to help with doing something to the current state
of affairs?
Thanks.
brettcannon commentedon Mar 31, 2009
On Tue, Mar 31, 2009 at 06:39, Aleksi Torhamo <[email protected]>wrote:
Beyond looking at what is in trunk, nothing specific comes to mind.
josiahcarlson commentedon Mar 31, 2009
Your analysis WRT handle_expt_event() is correct. I've been meaning to
fix that for a while, but I forgot to do it in 2.6/3.0 with all of the
other changes/fixes. Looking at the docs, you are also right about
POLLNVAL.
I also don't *know* what to do when presented with POLLERR, but few
socket errors are transient (transient errors should be handled by the
underlying stacks), so I agree with you that they should just be closed.
I went ahead and made the changes as you have suggested, and also made
the same change with the select-based loop. Errors on the socket just
result in closing the socket, resulting in _exception() -> close().
Thinking about it, I've also had a change of heart, and added a
frozenset object called 'ignore_log_types', which specifies the log
types to ignore. By default it is populated with 'warning', which
squelches all currently existing "unhandled * event" bits. If you use
self.log(arg) or self.log_info(one_arg), those lines are unchanged.
Handle_error() uses the "error" type, which is also nice, but which you
can also suppress with ease (though you really should be logging them so
you can fix your code).
I've attached a version that I think is pretty reasonable. Comments?
Questions?
alexer commentedon Mar 31, 2009
The _exception() -> close() change seems to be wrong. The third set of
select() is supposed to represent oob data, so the previous use in the
select-based loop should have been correct?
Other than that, i can't see anything wrong with it.
Maybe handle_expt_event should be reverted to the old one, that just
calls handle_expt, too? The current version seems to assume that it is
called on socket error conditions.
josiahcarlson commentedon Mar 31, 2009
You are right. Handling OOB data is within the "exceptional condition"
that the select document specifies.
I've added a check for error conditions within handle_expt_event(),
which induces a handle_close() on discovery of an error, handle_expt()
otherwise.
One thing to consider is that when there is OOB data, and when
handle_expt() isn't overridden, we will get churn because that data will
never be read from the socket. I'm thinking about tossing a
handle_close() as part of the default handle_expt() call.
Attached is an updated patch without the handle_close() in
handle_expt().
alexer commentedon Mar 31, 2009
Ah, you're right. I hadn't thought about the exceptional condition being
used to signal anything besides OOB.
Looks really good to me.
s/close/_exception/ in the select-based poll(), and i don't have
anything more to add.
josiahcarlson commentedon Mar 31, 2009
Fixed the close() call and committed to trunk. Python 2.6 tests pass
with the new version of the library. Calling it good :) .
giampaolo commentedon Mar 31, 2009
I still get some occasional EBADF failures when running pyftpdlib test
suite by using poll().
I think that it makes more sense moving the:
...lines at the top and return if handle_close() is called, as I did in
the patch attached to bpo-4501, which is:
giampaolo commentedon Mar 31, 2009
...after all no read/write methods should be called after the socket has
been closed.
josiahcarlson commentedon Mar 31, 2009
Good point Giampaolo. Fixed and committed.
giampaolo commentedon Mar 31, 2009
If you're talking about r70904 then you did a different thing than the
one I suggested.