Using latest python 2.6 branch; test_asynchat fails with the following
error:

error: uncaptured python exception, closing channel
<test.test_asynchat.echo_client at 0x1689238> (<class
'socket.error'>:[Errno 9] Bad file descriptor
[/Users/cartman/Sources/python-2.6/Lib/asyncore.py|readwrite|107]
[/Users/cartman/Sources/python-2.6/Lib/asyncore.py|handle_expt_event|441] [<string>|getsockopt|1]
[/Users/cartman/Sources/python-2.6/Lib/socket.py|_dummy|165])

Using Mac OSX 10.5.6.

I'm seeing this failure on 2.7, 3.0 and 3.1 as well.

Still fails in 3.1 beta1.

I tried to track this down, but ran out of time.  Here's
the little that I discovered;  maybe someone else with
access to OS X (which I have) and an understanding of
poll (which I lack) can build on this.

The failure has to do with select.poll differences between Linux
and OS X.  It seems that OS X can return POLLIN | POLLPRI | POLLHUP
in situations where Linux just returns POLLIN, and this combination
of flags causes the code in asyncore to first close the socket and
then try to read from it.  The relevant code is at around line 440
of Lib/asyncore.py.

r56632 looks relevant:

"""When running asynchat tests on OS X (darwin), the test client now
overrides asyncore.dispatcher.handle_expt to do nothing, since
select.poll gives a POLLHUP error at the completion of these tests.
Added timeout & count arguments to several asyncore.loop calls to
avoid the possibility of a test hanging up a build. [GSoC - Alan
McIntyre]"""

Adding Facundo Batista and Alan McIntyre to the nosy list.  Does either of 
you know what's going on with this issue?

Here is a (new?) failure of test_asynchat with Python 3.1b1 on MacOS X 
10.4.11 (Intel).

% make test
....
test test_asynchat produced unexpected output:
**********************************************************************
*** lines 2-16 of actual output doesn't appear in expected output after 
line 1:
+ error: uncaptured python exception, closing channel 
<test.test_asynchat.echo_client at 0x21dcc30> (<class 'socket.error'
>:[Errno 9] Bad file descriptor [../Python-
3.1b1/Lib/asyncore.py|readwrite|106] [../Python-3
.1b1/Lib/asyncore.py|handle_expt_event|440])
+ error: uncaptured python exception, closing channel 
<test.test_asynchat.echo_client at 0x21dcb90> (<class 'socket.error'
>:[Errno 9] Bad file descriptor [../Python-
3.1b1/Lib/asyncore.py|readwrite|106] [../Python-3
.1b1/Lib/asyncore.py|handle_expt_event|440])
+ error: uncaptured python exception, closing channel 
<test.test_asynchat.echo_client at 0x21dcf90> (<class 'socket.error'
>:[Errno 9] Bad file descriptor [../Python-
3.1b1/Lib/asyncore.py|readwrite|106] [../Python-3
.1b1/Lib/asyncore.py|handle_expt_event|440])
+ error: uncaptured python exception, closing channel 
<test.test_asynchat.echo_client at 0x21dcd50> (<class 'socket.error'
>:[Errno 9] Bad file descriptor [../Python-
3.1b1/Lib/asyncore.py|readwrite|106] [../Python-3
.1b1/Lib/asyncore.py|handle_expt_event|440])
+ error: uncaptured python exception, closing channel 
<test.test_asynchat.echo_client at 0x21dcc30> (<class 'socket.error'
>:[Errno 9] Bad file descriptor [../Python-
3.1b1/Lib/asyncore.py|readwrite|106] [../Python-3
.1b1/Lib/asyncore.py|handle_expt_event|440])
+ error: uncaptured python exception, closing channel 
<test.test_asynchat.echo_client at 0x21dcb90> (<class 'socket.error'
>:[Errno 9] Bad file descriptor [../Python-
3.1b1/Lib/asyncore.py|readwrite|106] [../Python-3
.1b1/Lib/asyncore.py|handle_expt_event|440])
+ error: uncaptured python exception, closing channel 
<test.test_asynchat.echo_client at 0x21dcf90> (<class 'socket.error'
>:[Errno 9] Bad file descriptor [../Python-
3.1b1/Lib/asyncore.py|readwrite|106] [../Python-3
.1b1/Lib/asyncore.py|handle_expt_event|440])
+ error: uncaptured python exception, closing channel 
<test.test_asynchat.echo_client at 0x21dcd50> (<class 'socket.error'
>:[Errno 9] Bad file descriptor [../Python-
3.1b1/Lib/asyncore.py|readwrite|106] [../Python-3
.1b1/Lib/asyncore.py|handle_expt_event|440])
+ error: uncaptured python exception, closing channel 
<test.test_asynchat.echo_client at 0x21dcc30> (<class 'socket.error'
>:[Errno 9] Bad file descriptor [../Python-
3.1b1/Lib/asyncore.py|readwrite|106] [../Python-3
.1b1/Lib/asyncore.py|handle_expt_event|440])
+ error: uncaptured python exception, closing channel 
<test.test_asynchat.echo_client at 0x21dcb90> (<class 'socket.error'
>:[Errno 9] Bad file descriptor [../Python-
3.1b1/Lib/asyncore.py|readwrite|106] [../Python-3
.1b1/Lib/asyncore.py|handle_expt_event|440])
+ error: uncaptured python exception, closing channel 
<test.test_asynchat.echo_client at 0x21dc2d0> (<class 'socket.error'
>:[Errno 9] Bad file descriptor [../Python-
3.1b1/Lib/asyncore.py|readwrite|106] [../Python-3
.1b1/Lib/asyncore.py|handle_expt_event|440])
+ error: uncaptured python exception, closing channel 
<test.test_asynchat.echo_client at 0x21dcc30> (<class 'socket.error'
>:[Errno 9] Bad file descriptor [../Python-
3.1b1/Lib/asyncore.py|readwrite|106] [../Python-3
.1b1/Lib/asyncore.py|handle_expt_event|440])
+ error: uncaptured python exception, closing channel 
<test.test_asynchat.echo_client at 0x21dcbb0> (<class 'socket.error'
>:[Errno 9] Bad file descriptor [../Python-
3.1b1/Lib/asyncore.py|readwrite|106] [../Python-3
.1b1/Lib/asyncore.py|handle_expt_event|440])
+ error: uncaptured python exception, closing channel 
<test.test_asynchat.echo_client at 0x21dcb90> (<class 'socket.error'
>:[Errno 9] Bad file descriptor [../Python-
3.1b1/Lib/asyncore.py|readwrite|106] [../Python-3
.1b1/Lib/asyncore.py|handle_expt_event|440])
+ error: uncaptured python exception, closing channel 
<test.test_asynchat.echo_client at 0x21dcd50> (<class 'socket.error'
>:[Errno 9] Bad file descriptor [../Python-
3.1b1/Lib/asyncore.py|readwrite|106] [../Python-3
.1b1/Lib/asyncore.py|handle_expt_event|440])
**********************************************************************
....

% ./python.exe Lib/test/test_asynchat.py
test_close_when_done (__main__.TestAsynchat) ... ok
test_empty_line (__main__.TestAsynchat) ... ok
test_line_terminator1 (__main__.TestAsynchat) ... ok
test_line_terminator2 (__main__.TestAsynchat) ... ok
test_line_terminator3 (__main__.TestAsynchat) ... ok
test_none_terminator (__main__.TestAsynchat) ... ok
test_numeric_terminator1 (__main__.TestAsynchat) ... ok
test_numeric_terminator2 (__main__.TestAsynchat) ... ok
test_simple_producer (__main__.TestAsynchat) ... ok
test_string_producer (__main__.TestAsynchat) ... ok
test_close_when_done (__main__.TestAsynchat_WithPoll) ... ok
test_empty_line (__main__.TestAsynchat_WithPoll) ... error: uncaptured 
python exception, closing channel <__main__.echo_client at 0x107cf30> 
(<class 'socket.error'>:[Errno 9] Bad file descriptor [../Python-
3.1b1/Lib/asyncore.py|readwrite|106] [../Python-
3.1b1/Lib/asyncore.py|handle_expt_event|440])
ok
test_line_terminator1 (__main__.TestAsynchat_WithPoll) ... error: 
uncaptured python exception, closing channel <__main__.echo_client at 
0x107c3f0> (<class 'socket.error'>:[Errno 9] Bad file descriptor 
[../Python-3.1b1/Lib/asyncore.py|readwrite|106] [../Python-
3.1b1/Lib/asyncore.py|handle_expt_event|440])
error: uncaptured python exception, closing channel 
<__main__.echo_client at 0x107ceb0> (<class 'socket.error'>:[Errno 9] 
Bad file descriptor [../Python-3.1b1/Lib/asyncore.py|readwrite|106] 
[../Python-3.1b1/Lib/asyncore.py|handle_expt_event|440])
error: uncaptured python exception, closing channel 
<__main__.echo_client at 0x107cf50> (<class 'socket.error'>:[Errno 9] 
Bad file descriptor [../Python-3.1b1/Lib/asyncore.py|readwrite|106] 
[../Python-3.1b1/Lib/asyncore.py|handle_expt_event|440])
ok
test_line_terminator2 (__main__.TestAsynchat_WithPoll) ... error: 
uncaptured python exception, closing channel <__main__.echo_client at 
0x107ce70> (<class 'socket.error'>:[Errno 9] Bad file descriptor 
[../Python-3.1b1/Lib/asyncore.py|readwrite|106] [../Python-
3.1b1/Lib/asyncore.py|handle_expt_event|440])
error: uncaptured python exception, closing channel 
<__main__.echo_client at 0x107ced0> (<class 'socket.error'>:[Errno 9] 
Bad file descriptor [../Python-3.1b1/Lib/asyncore.py|readwrite|106] 
[../Python-3.1b1/Lib/asyncore.py|handle_expt_event|440])
error: uncaptured python exception, closing channel 
<__main__.echo_client at 0x107cf30> (<class 'socket.error'>:[Errno 9] 
Bad file descriptor [../Python-3.1b1/Lib/asyncore.py|readwrite|106] 
[../Python-3.1b1/Lib/asyncore.py|handle_expt_event|440])
ok
test_line_terminator3 (__main__.TestAsynchat_WithPoll) ... error: 
uncaptured python exception, closing channel <__main__.echo_client at 
0x107ceb0> (<class 'socket.error'>:[Errno 9] Bad file descriptor 
[../Python-3.1b1/Lib/asyncore.py|readwrite|106] [../Python-
3.1b1/Lib/asyncore.py|handle_expt_event|440])
error: uncaptured python exception, closing channel 
<__main__.echo_client at 0x107cf50> (<class 'socket.error'>:[Errno 9] 
Bad file descriptor [../Python-3.1b1/Lib/asyncore.py|readwrite|106] 
[../Python-3.1b1/Lib/asyncore.py|handle_expt_event|440])
error: uncaptured python exception, closing channel 
<__main__.echo_client at 0x107cef0> (<class 'socket.error'>:[Errno 9] 
Bad file descriptor [../Python-3.1b1/Lib/asyncore.py|readwrite|106] 
[../Python-3.1b1/Lib/asyncore.py|handle_expt_event|440])
ok
test_none_terminator (__main__.TestAsynchat_WithPoll) ... error: 
uncaptured python exception, closing channel <__main__.echo_client at 
0x107cf50> (<class 'socket.error'>:[Errno 9] Bad file descriptor 
[../Python-3.1b1/Lib/asyncore.py|readwrite|106] [../Python-
3.1b1/Lib/asyncore.py|handle_expt_event|440])
ok
test_numeric_terminator1 (__main__.TestAsynchat_WithPoll) ... error: 
uncaptured python exception, closing channel <__main__.echo_client at 
0x107ce10> (<class 'socket.error'>:[Errno 9] Bad file descriptor 
[../Python-3.1b1/Lib/asyncore.py|readwrite|106] [../Python-
3.1b1/Lib/asyncore.py|handle_expt_event|440])
ok
test_numeric_terminator2 (__main__.TestAsynchat_WithPoll) ... error: 
uncaptured python exception, closing channel <__main__.echo_client at 
0x107ce50> (<class 'socket.error'>:[Errno 9] Bad file descriptor 
[../Python-3.1b1/Lib/asyncore.py|readwrite|106] [../Python-
3.1b1/Lib/asyncore.py|handle_expt_event|440])
ok
test_simple_producer (__main__.TestAsynchat_WithPoll) ... error: 
uncaptured python exception, closing channel <__main__.echo_client at 
0x107cdb0> (<class 'socket.error'>:[Errno 9] Bad file descriptor 
[../Python-3.1b1/Lib/asyncore.py|readwrite|106] [../Python-
3.1b1/Lib/asyncore.py|handle_expt_event|440])
ok
test_string_producer (__main__.TestAsynchat_WithPoll) ... error: 
uncaptured python exception, closing channel <__main__.echo_client at 
0x107cf50> (<class 'socket.error'>:[Errno 9] Bad file descriptor 
[../Python-3.1b1/Lib/asyncore.py|readwrite|106] [../Python-
3.1b1/Lib/asyncore.py|handle_expt_event|440])
ok
test_find_prefix_at_end (__main__.TestHelperFunctions) ... ok
test_basic (__main__.TestFifo) ... ok
test_given_list (__main__.TestFifo) ... ok

----------------------------------------------------------------------
Ran 23 tests in 7.712s

OK

See also issue 1161031, especially Giampaolo's suggestion near the end.
 Seems like it might be relevant.  I was the one who merged Josiah's
trunk fix into othe other branches, to get things back into sync, but I
don't claim to understand the code at any deep level.  From the review I
did at my level of knowledge it seems like the change to the behavior of
when handle_expt_event is called is correct, but I was a little worried
about backward compatibility.  I now wonder if that fix should be backed
out of 2.6 and 3.0, and advertised in What's New for 2.7 and 3.1.

Looking at trunk, it seems like one reasonable option is to swap the 
order of handle_close() and handle_expt_event() testing and calls.  That 
would keep all reading/writing before handle_close(), which should be 
correct.

Josiah, that solution isn't working for me;  it looks as though there's 
a deeper weirdness:  what I'm seeing is that on OS X, in e.g. 
test_emptyline, we end up calling the readwrite function in asyncore.py 
with flags = POLLIN | POLLPRI | POLLHUP.  The first thing that gets 
called is obj.handle.read_event, and bizarrely it seems to be the 
read_event call that has the effect of closing the socket.  So the 
socket's already closed by the time we get to obj.handle_expt_event and 
the same error as before occurs.

I'm still trying to figure out why.

So the sequence of events seems to be:
  asyncore.readwrite calls obj.handle_read_event
  ... which calls obj.handle_read (3rd branch of handle_read_event)
  ... which is defined in asynchat.py;  it calls obj.recv
  ... (back in asyncore now): recv calls obj.socket.recv
  ... and gets no data, so it then calls obj.handle_close
  ... which calls obj.close(), and so closes obj.socket as well.

and now obj.handle_expt_event gets confused because the socket is 
closed.

Now what?

It would seem that we need to be more defensive in our calls.  We need 
to check to make sure that the socket isn't closed before calling 
read/write/expt events.

Mark, try this:

        if flags & select.POLLIN and (obj.connected or obj.accepting):
            obj.handle_read_event()
        if flags & select.POLLOUT and obj.connected:
            obj.handle_write_event()
        if flags & select.POLLPRI and obj.connected:
            obj.handle_expt_event()
        if flags & (select.POLLHUP | select.POLLERR | select.POLLNVAL):
            obj.handle_close()

That fixes test_empty_line (in test_asynchat.py), but now I get a hang in 
test_close_when_done.

By the way, here's an interesting site that goes some way to explaining 
what to expect from select.poll and EOF.

http://www.greenend.org.uk/rjk/2001/06/poll.html

Try getting rid of the "and" clause in the select.POLLIN .

To be clear, make the first test read...
        if flags & select.POLLIN:
            obj.handle_read_event()

Getting rid of the and ... on the handle_read_event didn't make a 
difference:  I still get the hang in test_close_when_done.

But if I get rid of the and clause on the handle_write_event branch then
all the test_asynchat tests pass.  So that block now looks like:

        if flags & select.POLLIN and (obj.connected or obj.accepting):
            obj.handle_read_event()
        if flags & select.POLLOUT:
            obj.handle_write_event()
        if flags & select.POLLPRI and obj.connected:
            obj.handle_expt_event()
        if flags & (select.POLLHUP | select.POLLERR | select.POLLNVAL):
            obj.handle_close()

in my code.  So we're making progress (maybe). Unfortunately, 
test_asyncore now fails with:

======================================================================
FAIL: test_readwrite (__main__.HelperFunctionTests)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "Lib/test/test_asyncore.py", line 161, in test_readwrite
    self.assertEqual(getattr(tobj, attr), attr==expectedattr)
AssertionError: False != True

I went ahead and plugged my mac in (which reminded me of why I unplugged 
it in the first place), and I'm able to reproduce your error in the test 
after my proposed modifications.

One thing to remember is that the test is broken; we rely on a 
.connected attribute, which the test objects lack.

The attached patch fixes the test on my OS X machine, which you should 
test.

I reran the test_synchat.py test after patching to the Lib/asyncore.py 
and Lib/test/test-asynchat.py files of Python-3.1b1 on MacOS X 10.4.11 
(Intel).

The test now hangs in
...
test_string_producer (__main__.TestAsynchat) ... ok
test_close_when_done (__main__.TestAsynchat_WithPoll) ...

The test also hangs, after removing the patches from the 
Lib/test/test_asynchat.py file but keeping the patched Lib/asyncore.py 
file.

As an aside, I was testing against trunk, not 3.1b1 .

Understood.

On Thu, May 7, 2009 at 5:18 PM, Josiah Carlson <report@bugs.python.org>wrote:

>
> Josiah Carlson <josiahcarlson@users.sourceforge.net> added the comment:
>
> As an aside, I was testing against trunk, not 3.1b1 .
>
> ----------
>
> _______________________________________
> Python tracker <report@bugs.python.org>
> <http://bugs.python.org/issue5798>
> _______________________________________
>

Has anyone already tried to modify readwrite() as I was suggesting here?
http://bugs.python.org/issue1161031#msg84892

Indeed, the unmodified test_asynchat.py now passes in Python 3.1b1.  The 
readwrite function in asyncore looks like this now:

def readwrite(obj, flags):
    try:
        if flags & (select.POLLHUP | select.POLLERR | select.POLLNVAL):
            obj.handle_close()
        else:
            if flags & select.POLLIN:
                obj.handle_read_event()
            if flags & select.POLLOUT:  # and obj.connected:
                obj.handle_write_event()
            if flags & select.POLLPRI:  # and obj.connected:
                obj.handle_expt_event()
    except _reraised_exceptions:
        raise
    except:
        obj.handle_error()

One of the issues with using the method that Giampaolo describes, which 
I explained to him, is that generally if someone sends you data, you 
want to receive it.  You can get both data and the signal that someone 
disconnected, in particular, with asynchat's .close_when_done() method.

If you get a read signal, generally you want to try to pull more data 
before you close, because when you close, you can never get any pending 
data again.

For example, if I were to use:
  chat.send("commit\n")
  chat.close_when_done()
It's very likely that on even moderate latency network connections 
(10ms), the other end would get the close signal at the same time as the 
read for the "commit\n" message.  But since they close before they read, 
they never get the "commit" message, and maybe a transaction is 
reverted.

My primary concern is keeping the library correct.  Adding attributes in 
the test cases don't bother me.

Jean: on what platform are you experiencing the hang?  Are you using 
trunk or 3.1?

With Josiah's patch, on trunk (r72475), test_asyncore passes, but
test_asynchat is still hanging in the test:

test_close_when_done (__main__.TestAsynchat_WithPoll) ... 

The hang occurs at the line "data = conn.recv(1)" in the run method
of the echo_server class in Lib/test/test_asynchat.py.

With Giampaolo's suggested change, all tests pass.  My understanding of 
what asyncore/asynchat is intended to do and how it might be used in 
practice is weak, so I don't feel qualified to comment on the 
correctness of the change.

> One of the issues with using the method that Giampaolo describes, 
which 
> I explained to him, is that generally if someone sends you data, you 
> want to receive it.  You can get both data and the signal that someone 
> disconnected, in particular, with asynchat's .close_when_done() 
method.

Is it possible to add a test for this sort of situation, to make sure 
that future changes take it into account?

Ok, so I was running "test_asyncore" and not "test_asynchat".

The issue on OS X is that when a new socket is connecting, select.poll() 
shows the socket as being writable when it first connects, but using my 
variant, .connected is False while it's waiting for the connection.

Options:
If we swap the pollin/pollout conditions, that would fix the hang on 
mac, but cause the hang on others (I'm not really worried about not 
doing a write after a read, .push() in asynchat performs an immediate 
send).

If we get rid of the .connected check, then when a .read() fails and 
causes a close, then we get an exception in handle_write().

If we swap to Giampaolo's variant, then we could lose data that was 
legitimately sent by a client.

I've got a version that doesn't hang on OS X, and should work on all 
platforms.  It's ugly, but it works.

asyncore_fix_mac_2.patch fixes all test_failures for me, on both trunk and 
py3k.

Here's an option that doesn't use .connected, which some people have 
expressed distaste for.

def readwrite(obj, flags):
    try:
        if flags & select.POLLIN:
            obj.handle_read_event()
        if flags & select.POLLOUT:
            obj.handle_write_event()
        if flags & select.POLLPRI:
            obj.handle_expt_event()
        if flags & (select.POLLHUP | select.POLLERR | select.POLLNVAL):
            obj.handle_close()
    except socket.error, e:
        if e.args[0] not in (EBADF, ECONNRESET, ENOTCONN, ESHUTDOWN, 
ECONNABORTED):
            obj.handle_error()
        else:
            obj.handle_close()
    except _reraised_exceptions:
        raise
    except:
        obj.handle_error()

It works on OS X and should work just as well on other platforms.

Even if that patch would fix this issue (and I'm pretty sure it does) I
don't think it's a good idea handling all those errors (EBADF,
ECONNRESET, ENOTCONN, ESHUTDOWN, ECONNABORTED) in readwrite() function.

Although those error codes unmistakably remark a disconnect event
condition (EBADF too? are we sure it *always* means that?) I would
prefer that be done in asyncore.dispatcher() and handle_close() be
called from there.

That's the implementation asyncore has always used until now where the
poller logic (poll(), poll2()) has always been kept separated from the
connection logic (asyncore.dispatcher) where the "if socket.err[0] in
..." stuff is done.


Unfortunately I haven't got an OS X box to test against and verify by
myself, but If I'm not mistaken by looking at the traceback messages
pasted by other folks, it seems that the exception takes place in
handle_expt_event() at this point:

err = self.socket.getsockopt(socket.SOL_SOCKET, socket.SO_ERROR)

If that's the case I think it makes more sense catching EBADF from there
rather than breaking the logic used so far, also because, if I'm not
mistaken, the problem has been introduced by this very line which has
been added in Python 2.6.

Still happening on 3.1rc1.

Should this be considered a release blocker for 3.1?

If it's failing, and asyncore is still in 3.1, then I would argue yes.

I'll submit a fix to trunk and 3.1 based on my version below (unless 
anyone has any outstanding concerns, or believes that it doesn't work for 
them).

Fixed in trunk in 73182, fixed in py3k in 73183.

Closing as fixed.

Verified test_asynchat no longer fails in trunk nor py3k.  Thanks!

Well, with fresh build of Python 3.1rc1 on MacOS X 10.4.11 Tiger (Intel) test_asynchat.py rev 73183 still seems to 
fail, perhaps differently.  Here is 3 different results.  First, rev 73183:

% ./python.exe  Lib/test/test_asynchat73183.py
test_close_when_done (__main__.TestAsynchat) ... ok
test_empty_line (__main__.TestAsynchat) ... ok
test_line_terminator1 (__main__.TestAsynchat) ... ok
test_line_terminator2 (__main__.TestAsynchat) ... ok
test_line_terminator3 (__main__.TestAsynchat) ... ok
test_none_terminator (__main__.TestAsynchat) ... ok
test_numeric_terminator1 (__main__.TestAsynchat) ... ok
test_numeric_terminator2 (__main__.TestAsynchat) ... ok
test_simple_producer (__main__.TestAsynchat) ... ok
test_string_producer (__main__.TestAsynchat) ... ok
test_close_when_done (__main__.TestAsynchat_WithPoll) ... ok
test_empty_line (__main__.TestAsynchat_WithPoll) ... error: uncaptured python exception, closing channel 
<__main__.echo_client at 0x10835b0> (<class 'socket.error'>:[Errno 9] Bad file descriptor [../Python-
3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-3.1rc1/Lib/asyncore.py|handle_expt_event|440])
ok
test_line_terminator1 (__main__.TestAsynchat_WithPoll) ... error: uncaptured python exception, closing channel 
<__main__.echo_client at 0x1083550> (<class 'socket.error'>:[Errno 9] Bad file descriptor [../Python-
3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-3.1rc1/Lib/asyncore.py|handle_expt_event|440])
error: uncaptured python exception, closing channel <__main__.echo_client at 0x1083610> (<class 
'socket.error'>:[Errno 9] Bad file descriptor [../Python-3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-
3.1rc1/Lib/asyncore.py|handle_expt_event|440])
error: uncaptured python exception, closing channel <__main__.echo_client at 0x10835f0> (<class 
'socket.error'>:[Errno 9] Bad file descriptor [../Python-3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-
3.1rc1/Lib/asyncore.py|handle_expt_event|440])
ok
test_line_terminator2 (__main__.TestAsynchat_WithPoll) ... error: uncaptured python exception, closing channel 
<__main__.echo_client at 0x1083630> (<class 'socket.error'>:[Errno 9] Bad file descriptor [../Python-
3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-3.1rc1/Lib/asyncore.py|handle_expt_event|440])
error: uncaptured python exception, closing channel <__main__.echo_client at 0x1083870> (<class 
'socket.error'>:[Errno 9] Bad file descriptor [../Python-3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-
3.1rc1/Lib/asyncore.py|handle_expt_event|440])
error: uncaptured python exception, closing channel <__main__.echo_client at 0x10838b0> (<class 
'socket.error'>:[Errno 9] Bad file descriptor [../Python-3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-
3.1rc1/Lib/asyncore.py|handle_expt_event|440])
ok
test_line_terminator3 (__main__.TestAsynchat_WithPoll) ... error: uncaptured python exception, closing channel 
<__main__.echo_client at 0x1083610> (<class 'socket.error'>:[Errno 9] Bad file descriptor [../Python-
3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-3.1rc1/Lib/asyncore.py|handle_expt_event|440])
error: uncaptured python exception, closing channel <__main__.echo_client at 0x1083550> (<class 
'socket.error'>:[Errno 9] Bad file descriptor [../Python-3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-
3.1rc1/Lib/asyncore.py|handle_expt_event|440])
error: uncaptured python exception, closing channel <__main__.echo_client at 0x10835f0> (<class 
'socket.error'>:[Errno 9] Bad file descriptor [../Python-3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-
3.1rc1/Lib/asyncore.py|handle_expt_event|440])
ok
test_none_terminator (__main__.TestAsynchat_WithPoll) ... error: uncaptured python exception, closing channel 
<__main__.echo_client at 0x1083550> (<class 'socket.error'>:[Errno 9] Bad file descriptor [../Python-
3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-3.1rc1/Lib/asyncore.py|handle_expt_event|440])
ok
test_numeric_terminator1 (__main__.TestAsynchat_WithPoll) ... error: uncaptured python exception, closing channel 
<__main__.echo_client at 0x1083630> (<class 'socket.error'>:[Errno 9] Bad file descriptor [../Python-
3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-3.1rc1/Lib/asyncore.py|handle_expt_event|440])
ok
test_numeric_terminator2 (__main__.TestAsynchat_WithPoll) ... error: uncaptured python exception, closing channel 
<__main__.echo_client at 0x10837f0> (<class 'socket.error'>:[Errno 9] Bad file descriptor [../Python-
3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-3.1rc1/Lib/asyncore.py|handle_expt_event|440])
ok
test_simple_producer (__main__.TestAsynchat_WithPoll) ... error: uncaptured python exception, closing channel 
<__main__.echo_client at 0x1083910> (<class 'socket.error'>:[Errno 9] Bad file descriptor [../Python-
3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-3.1rc1/Lib/asyncore.py|handle_expt_event|440])
ok
test_string_producer (__main__.TestAsynchat_WithPoll) ... error: uncaptured python exception, closing channel 
<__main__.echo_client at 0x10835b0> (<class 'socket.error'>:[Errno 9] Bad file descriptor [../Python-
3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-3.1rc1/Lib/asyncore.py|handle_expt_event|440])
ok
test_find_prefix_at_end (__main__.TestHelperFunctions) ... ok
test_basic (__main__.TestFifo) ... ok
test_given_list (__main__.TestFifo) ... ok

----------------------------------------------------------------------
Ran 23 tests in 7.717s

OK


Second, this is the result of test_asyncat.py included in Python 3.1rc1:

% ./python.exe Lib/test/test_asynchat.py
test_close_when_done (__main__.TestAsynchat) ... ok
test_empty_line (__main__.TestAsynchat) ... ok
test_line_terminator1 (__main__.TestAsynchat) ... ok
test_line_terminator2 (__main__.TestAsynchat) ... ok
test_line_terminator3 (__main__.TestAsynchat) ... ok
test_none_terminator (__main__.TestAsynchat) ... ok
test_numeric_terminator1 (__main__.TestAsynchat) ... ok
test_numeric_terminator2 (__main__.TestAsynchat) ... ok
test_simple_producer (__main__.TestAsynchat) ... ok
test_string_producer (__main__.TestAsynchat) ... ok
test_close_when_done (__main__.TestAsynchat_WithPoll) ... ok
test_empty_line (__main__.TestAsynchat_WithPoll) ... error: uncaptured python exception, closing channel 
<__main__.echo_client at 0x10835b0> (<class 'socket.error'>:[Errno 9] Bad file descriptor [../Python-
3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-3.1rc1/Lib/asyncore.py|handle_expt_event|440])
ok
test_line_terminator1 (__main__.TestAsynchat_WithPoll) ... error: uncaptured python exception, closing channel 
<__main__.echo_client at 0x1083550> (<class 'socket.error'>:[Errno 9] Bad file descriptor [../Python-
3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-3.1rc1/Lib/asyncore.py|handle_expt_event|440])
error: uncaptured python exception, closing channel <__main__.echo_client at 0x1083610> (<class 
'socket.error'>:[Errno 9] Bad file descriptor [../Python-3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-
3.1rc1/Lib/asyncore.py|handle_expt_event|440])
error: uncaptured python exception, closing channel <__main__.echo_client at 0x10835f0> (<class 
'socket.error'>:[Errno 9] Bad file descriptor [../Python-3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-
3.1rc1/Lib/asyncore.py|handle_expt_event|440])
ok
test_line_terminator2 (__main__.TestAsynchat_WithPoll) ... error: uncaptured python exception, closing channel 
<__main__.echo_client at 0x1083630> (<class 'socket.error'>:[Errno 9] Bad file descriptor [../Python-
3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-3.1rc1/Lib/asyncore.py|handle_expt_event|440])
error: uncaptured python exception, closing channel <__main__.echo_client at 0x1083870> (<class 
'socket.error'>:[Errno 9] Bad file descriptor [../Python-3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-
3.1rc1/Lib/asyncore.py|handle_expt_event|440])
error: uncaptured python exception, closing channel <__main__.echo_client at 0x10838b0> (<class 
'socket.error'>:[Errno 9] Bad file descriptor [../Python-3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-
3.1rc1/Lib/asyncore.py|handle_expt_event|440])
ok
test_line_terminator3 (__main__.TestAsynchat_WithPoll) ... error: uncaptured python exception, closing channel 
<__main__.echo_client at 0x1083610> (<class 'socket.error'>:[Errno 9] Bad file descriptor [../Python-
3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-3.1rc1/Lib/asyncore.py|handle_expt_event|440])
error: uncaptured python exception, closing channel <__main__.echo_client at 0x1083550> (<class 
'socket.error'>:[Errno 9] Bad file descriptor [../Python-3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-
3.1rc1/Lib/asyncore.py|handle_expt_event|440])
error: uncaptured python exception, closing channel <__main__.echo_client at 0x10835f0> (<class 
'socket.error'>:[Errno 9] Bad file descriptor [../Python-3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-
3.1rc1/Lib/asyncore.py|handle_expt_event|440])
ok
test_none_terminator (__main__.TestAsynchat_WithPoll) ... error: uncaptured python exception, closing channel 
<__main__.echo_client at 0x1083550> (<class 'socket.error'>:[Errno 9] Bad file descriptor [../Python-
3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-3.1rc1/Lib/asyncore.py|handle_expt_event|440])
ok
test_numeric_terminator1 (__main__.TestAsynchat_WithPoll) ... error: uncaptured python exception, closing channel 
<__main__.echo_client at 0x1083670> (<class 'socket.error'>:[Errno 9] Bad file descriptor [../Python-
3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-3.1rc1/Lib/asyncore.py|handle_expt_event|440])
ok
test_numeric_terminator2 (__main__.TestAsynchat_WithPoll) ... error: uncaptured python exception, closing channel 
<__main__.echo_client at 0x10837f0> (<class 'socket.error'>:[Errno 9] Bad file descriptor [../Python-
3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-3.1rc1/Lib/asyncore.py|handle_expt_event|440])
ok
test_simple_producer (__main__.TestAsynchat_WithPoll) ... error: uncaptured python exception, closing channel 
<__main__.echo_client at 0x1083910> (<class 'socket.error'>:[Errno 9] Bad file descriptor [../Python-
3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-3.1rc1/Lib/asyncore.py|handle_expt_event|440])
ok
test_string_producer (__main__.TestAsynchat_WithPoll) ... error: uncaptured python exception, closing channel 
<__main__.echo_client at 0x10835b0> (<class 'socket.error'>:[Errno 9] Bad file descriptor [../Python-
3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-3.1rc1/Lib/asyncore.py|handle_expt_event|440])
ok
test_find_prefix_at_end (__main__.TestHelperFunctions) ... ok
test_basic (__main__.TestFifo) ... ok
test_given_list (__main__.TestFifo) ... ok

----------------------------------------------------------------------
Ran 23 tests in 7.721s

OK


Both are not the exact same, but equivalent.  Lastly, here are 4 snippets from the 'make test' output.

....<deleted>....

test test_asynchat produced unexpected output:
**********************************************************************
*** lines 2-16 of actual output doesn't appear in expected output after line 1:
+ error: uncaptured python exception, closing channel <test.test_asynchat.echo_client at 0x22704f0> (<class 
'socket.error'
>:[Errno 9] Bad file descriptor [../Python-3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-
3.1rc1/Lib/asyncore.py|handle_expt_event|440])
+ error: uncaptured python exception, closing channel <test.test_asynchat.echo_client at 0x2270b10> (<class 
'socket.error'
>:[Errno 9] Bad file descriptor [../Python-3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-
3.1rc1/Lib/asyncore.py|handle_expt_event|440])
+ error: uncaptured python exception, closing channel <test.test_asynchat.echo_client at 0x22704b0> (<class 
'socket.error'
>:[Errno 9] Bad file descriptor [../Python-3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-
3.1rc1/Lib/asyncore.py|handle_expt_event|440])
+ error: uncaptured python exception, closing channel <test.test_asynchat.echo_client at 0x2270470> (<class 
'socket.error'
>:[Errno 9] Bad file descriptor [../Python-3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-
3.1rc1/Lib/asyncore.py|handle_expt_event|440])
+ error: uncaptured python exception, closing channel <test.test_asynchat.echo_client at 0x22703d0> (<class 
'socket.error'
>:[Errno 9] Bad file descriptor [../Python-3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-
3.1rc1/Lib/asyncore.py|handle_expt_event|440])
+ error: uncaptured python exception, closing channel <test.test_asynchat.echo_client at 0x2270450> (<class 
'socket.error'
>:[Errno 9] Bad file descriptor [../Python-3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-
3.1rc1/Lib/asyncore.py|handle_expt_event|440])
+ error: uncaptured python exception, closing channel <test.test_asynchat.echo_client at 0x22704f0> (<class 
'socket.error'
>:[Errno 9] Bad file descriptor [../Python-3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-
3.1rc1/Lib/asyncore.py|handle_expt_event|440])
+ error: uncaptured python exception, closing channel <test.test_asynchat.echo_client at 0x22704b0> (<class 
'socket.error'
>:[Errno 9] Bad file descriptor [../Python-3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-
3.1rc1/Lib/asyncore.py|handle_expt_event|440])
+ error: uncaptured python exception, closing channel <test.test_asynchat.echo_client at 0x2270b10> (<class 
'socket.error'
>:[Errno 9] Bad file descriptor [../Python-3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-
3.1rc1/Lib/asyncore.py|handle_expt_event|440])
+ error: uncaptured python exception, closing channel <test.test_asynchat.echo_client at 0x2270530> (<class 
'socket.error'
>:[Errno 9] Bad file descriptor [../Python-3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-
3.1rc1/Lib/asyncore.py|handle_expt_event|440])
+ error: uncaptured python exception, closing channel <test.test_asynchat.echo_client at 0x2270b10> (<class 
'socket.error'
>:[Errno 9] Bad file descriptor [../Python-3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-
3.1rc1/Lib/asyncore.py|handle_expt_event|440])
+ error: uncaptured python exception, closing channel <test.test_asynchat.echo_client at 0x2270470> (<class 
'socket.error'
>:[Errno 9] Bad file descriptor [../Python-3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-
3.1rc1/Lib/asyncore.py|handle_expt_event|440])
+ error: uncaptured python exception, closing channel <test.test_asynchat.echo_client at 0x22704d0> (<class 
'socket.error'
>:[Errno 9] Bad file descriptor [../Python-3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-
3.1rc1/Lib/asyncore.py|handle_expt_event|440])
+ error: uncaptured python exception, closing channel <test.test_asynchat.echo_client at 0x22709f0> (<class 
'socket.error'
>:[Errno 9] Bad file descriptor [../Python-3.1rc1/Lib/asyncore.py|readwrite|106] [../Python-
3.1rc1/Lib/asyncore.py|handle_expt_event|440])
+ error: uncaptured python exception, closing channel <test.test_asynchat.echo_client at 0x2270b10> (<class 
'socket.error'
>:[Errno 9] Bad file descriptor [../Python-3.1rc1/Lib/asyncore.py|readwrite|106] [../Tools/Python-
3.1rc1/Lib/asyncore.py|handle_expt_event|440])
**********************************************************************
....<deleted>....

test_cmd_line
test test_cmd_line failed -- Traceback (most recent call last):
  File "../Tools/Python-3.1rc1/Lib/test/test_cmd_line.py", line 145, in test_run_code
    0)
AssertionError: 1 != 0
....<deleted>....

test test_smtplib produced unexpected output:
**********************************************************************
*** line 2 of actual output doesn't appear in expected output after line 1:
+ error: uncaptured python exception, closing channel <test.test_smtplib.SimSMTPChannel 127.0.0.1:50714 at 
0x3b21ff0> (<cl
ass 'socket.error'>:[Errno 9] Bad file descriptor [../Python-3.1rc1/Lib/asyncore.py|readwrite|106] [/Users/
../Python-3.1rc1/Lib/asyncore.py|handle_expt_event|440])
**********************************************************************
....<deleted>....

308 tests OK.
3 tests failed:
    test_asynchat test_cmd_line test_smtplib
25 tests skipped:
    test_codecmaps_cn test_codecmaps_hk test_codecmaps_jp
    test_codecmaps_kr test_codecmaps_tw test_curses test_dbm_gnu
    test_epoll test_largefile test_nis test_normalization
    test_ossaudiodev test_pep277 test_smtpnet test_socketserver
    test_startfile test_timeout test_tk test_ttk_guionly
    test_urllib2net test_urllibnet test_winreg test_winsound
    test_xmlrpc_net test_zipfile64
Those skips are all expected on darwin.
make: *** [test] Error 1

I presume you mean "a fresh build of 3.1rc1+" (from svn)?  3.1rc1 does
not contain the most recent fix.

I installed 3.1rc1 on my OS X (10.5.?) machine, updated asynchat, and ran 
the test with and without my change.  Without my change, it breaks in the 
way described numerous times.  With my change, it seems to work fine on OS 
X, linux, and Windows for me.

Looking at line 106 in py3k/Lib/asyncore.py 
(http://svn.python.org/view/python/branches/py3k/Lib/asyncore.py?
annotate=73183) gets me "obj.handle_close()".  Your tracebacks show line 
106 calling "obj.handle_expt_event()", which is the old code.

Correct.  With new Lib/asyncore.py file rev 73183 all 23 tests in the 
original test_asynchat.py pass in Python 3.1rc1 built from source on 
MacOS X 10.4.11 Tiger (Intel).

% ./python.exe Lib/test/test_asynchat.py
test_close_when_done (__main__.TestAsynchat) ... ok
test_empty_line (__main__.TestAsynchat) ... ok
test_line_terminator1 (__main__.TestAsynchat) ... ok
test_line_terminator2 (__main__.TestAsynchat) ... ok
test_line_terminator3 (__main__.TestAsynchat) ... ok
test_none_terminator (__main__.TestAsynchat) ... ok
test_numeric_terminator1 (__main__.TestAsynchat) ... ok
test_numeric_terminator2 (__main__.TestAsynchat) ... ok
test_simple_producer (__main__.TestAsynchat) ... ok
test_string_producer (__main__.TestAsynchat) ... ok
test_close_when_done (__main__.TestAsynchat_WithPoll) ... ok
test_empty_line (__main__.TestAsynchat_WithPoll) ... ok
test_line_terminator1 (__main__.TestAsynchat_WithPoll) ... ok
test_line_terminator2 (__main__.TestAsynchat_WithPoll) ... ok
test_line_terminator3 (__main__.TestAsynchat_WithPoll) ... ok
test_none_terminator (__main__.TestAsynchat_WithPoll) ... ok
test_numeric_terminator1 (__main__.TestAsynchat_WithPoll) ... ok
test_numeric_terminator2 (__main__.TestAsynchat_WithPoll) ... ok
test_simple_producer (__main__.TestAsynchat_WithPoll) ... ok
test_string_producer (__main__.TestAsynchat_WithPoll) ... ok
test_find_prefix_at_end (__main__.TestHelperFunctions) ... ok
test_basic (__main__.TestFifo) ... ok
test_given_list (__main__.TestFifo) ... ok

----------------------------------------------------------------------
Ran 23 tests in 7.726s

OK

Josiah's fix in r73182 applies cleanly to the release26-maint branch, and fixes (for me, at least) the current OS X failures in test_asynchat and test_smtplib.  I've attached a patch with the backport of this fix, and a Misc/NEWS entry.

Barry, can this go in before 2.6.6 final?

Thanks Mark, go ahead and apply this, then close this issue.

Applied in r83718.