msg85125 - (view) |
Author: Giampaolo Rodola' (giampaolo.rodola) * |
Date: 2009-04-02 01:03 |
I received a report from a pyftpdlib user:
http://code.google.com/p/pyftpdlib/issues/detail?id=104
...complaining that an unhandled EPIPE error might be thrown by
asyncore.py on OS X in certain circumstances which are hardly reproducible.
By googling a little about it it seems that he's not the first one who
got this problem:
http://mail.python.org/pipermail/medusa-dev/2003/000852.html
https://bugs.launchpad.net/zope2/+bug/142654
I think it makes sense modifying dispatcher.send() and dispatcher.recv()
to include EPIPE as error condition to indicate that the connection has
been closed and call handle_close() as consequence.
The patch in attachment does that.
|
msg85127 - (view) |
Author: Josiah Carlson (josiahcarlson) * |
Date: 2009-04-02 01:19 |
I think that catching one more potential failure modes is reasonable.
I'm probably going to apply a variant of this patch to pull the sequence
into a frozenset for quick lookups, and so that we don't need to keep
updating two different places if/when new failure conditions arise.
|
msg139199 - (view) |
Author: Terry J. Reedy (terry.reedy) * |
Date: 2011-06-26 19:26 |
I am not marking 'test needed' since the problem is 'hardly reproducible'.
|
msg146452 - (view) |
Author: Xavier de Gaye (xdegaye) * |
Date: 2011-10-26 19:24 |
> I am not marking 'test needed' since the problem is 'hardly reproducible'.
The attached script named 'asyncore_epipe.py' may be used to reproduce
systematically the EPIPE error on linux with Python 3.2:
* the Reader closes the socket after receiving the first data
* the Writer gets an exception when attempting to write the next
message on the closed socket
When you run 'python asyncore_epipe.py' or 'python asyncore_epipe.py
1025' you get an EPIPE error (1025 is the size of exchanged messages,
so the last Writer message has been fully read by the Reader before
closing).
When you run 'python asyncore_epipe.py 128' you get an ECONNRESET (the
Reader reads only 128 bytes before closing the socket)
Note that ECONNRESET has been removed in this script, from the
frozenset of handled errors, to make this last point visible.
So it seems that, on linux, when writing to a closed socket, you get
an ECONNRESET when there is still data in the socket, and an EPIPE
otherwise. In the first case the tcp connection ends with a single
RESET, and in the second case it ends with the sequence FIN-ACK-RESET.
|
msg146487 - (view) |
Author: Xavier de Gaye (xdegaye) * |
Date: 2011-10-27 14:38 |
Uploaded the patch 'epipe-default.patch' with a test case that breaks
on linux when EPIPE is not handled by asyncore, which is the case with
Python 3.2 and previous versions.
|
msg146488 - (view) |
Author: Xavier de Gaye (xdegaye) * |
Date: 2011-10-27 14:39 |
Uploaded the same test case for Python 2.7.
|
msg146510 - (view) |
Author: Charles-François Natali (neologix) * |
Date: 2011-10-27 17:58 |
Did you try with the current branches?
AFAICT, this should have been solved by 208a5290fd38 (issue #11265), and I did a quick test with default and it seems to be fixed.
In any case, it's probably a good idea to add this test to test_asyncore.
> So it seems that, on linux, when writing to a closed socket, you get
> an ECONNRESET when there is still data in the socket, and an EPIPE
> otherwise. In the first case the tcp connection ends with a single
> RESET, and in the second case it ends with the sequence FIN-ACK-RESET.
Yes, see RFC1122 section 4.2.2.13:
"""
A host MAY implement a "half-duplex" TCP close sequence, so
that an application that has called CLOSE cannot continue to
read data from the connection. If such a host issues a
CLOSE call while received data is still pending in TCP, or
if new data is received after CLOSE is called, its TCP
SHOULD send a RST to show that data was lost.
"""
|
msg146514 - (view) |
Author: Xavier de Gaye (xdegaye) * |
Date: 2011-10-27 18:37 |
> Did you try with the current branches?
Yes, the test is pass against the current default and 2.7 branches.
One must remove EPIPE from the asyncore._DISCONNECTED frozenset to
make the test to fail.
> Yes, see RFC1122 section 4.2.2.13:
> """
> A host MAY implement a "half-duplex" TCP close sequence, so
> that an application that has called CLOSE cannot continue to
> read data from the connection. If such a host issues a
> CLOSE call while received data is still pending in TCP, or
> if new data is received after CLOSE is called, its TCP
> SHOULD send a RST to show that data was lost.
> """
Thanks for the pointer. Note that the "half-duplex" FIN-ACK-RESET
occurs when all received data has been read, and a single RESET is
sent when received data is still pending in the stream.
|
msg146537 - (view) |
Author: Charles-François Natali (neologix) * |
Date: 2011-10-28 06:38 |
>> Did you try with the current branches?
>
> Yes, the test is pass against the current default and 2.7 branches.
> One must remove EPIPE from the asyncore._DISCONNECTED frozenset to
> make the test to fail.
OK. Then I'll add this test to test_asyncore.
|
msg146602 - (view) |
Author: Roundup Robot (python-dev) |
Date: 2011-10-29 10:42 |
New changeset bf1c4984d4e5 by Charles-François Natali in branch 'default':
Issue #5661: Add a test for ECONNRESET/EPIPE handling to test_asyncore. Patch
http://hg.python.org/cpython/rev/bf1c4984d4e5
|
msg146604 - (view) |
Author: Charles-François Natali (neologix) * |
Date: 2011-10-29 11:37 |
The test fails on OS X:
"""
======================================================================
ERROR: test_handle_close_after_conn_broken (test.test_asyncore.TestAPI_UseIPv4Poll)
----------------------------------------------------------------------
Traceback (most recent call last):
File "/Users/buildbot/buildarea/3.x.parc-snowleopard-1/build/Lib/test/test_asyncore.py", line 661, in test_handle_close_after_conn_broken
self.loop_waiting_for_flag(client)
File "/Users/buildbot/buildarea/3.x.parc-snowleopard-1/build/Lib/test/test_asyncore.py", line 523, in loop_waiting_for_flag
asyncore.loop(timeout=0.01, count=1, use_poll=self.use_poll)
File "/Users/buildbot/buildarea/3.x.parc-snowleopard-1/build/Lib/asyncore.py", line 215, in loop
poll_fun(timeout, map)
File "/Users/buildbot/buildarea/3.x.parc-snowleopard-1/build/Lib/asyncore.py", line 196, in poll2
readwrite(obj, flags)
File "/Users/buildbot/buildarea/3.x.parc-snowleopard-1/build/Lib/asyncore.py", line 123, in readwrite
obj.handle_error()
File "/Users/buildbot/buildarea/3.x.parc-snowleopard-1/build/Lib/asyncore.py", line 112, in readwrite
obj.handle_expt_event()
File "/Users/buildbot/buildarea/3.x.parc-snowleopard-1/build/Lib/asyncore.py", line 476, in handle_expt_event
self.handle_expt()
File "/Users/buildbot/buildarea/3.x.parc-snowleopard-1/build/Lib/test/test_asyncore.py", line 470, in handle_expt
raise Exception("handle_expt not supposed to be called")
Exception: handle_expt not supposed to be called
"""
Looks like the FD is returned in the exception set on OS X...
|
msg146605 - (view) |
Author: Roundup Robot (python-dev) |
Date: 2011-10-29 12:26 |
New changeset 507dfb0ceb3b by Charles-François Natali in branch 'default':
Issue #5661: on EPIPE/ECONNRESET, OS X returns the FD with the POLLPRI flag...
http://hg.python.org/cpython/rev/507dfb0ceb3b
|
msg146606 - (view) |
Author: Xavier de Gaye (xdegaye) * |
Date: 2011-10-29 12:27 |
The test fails when use_poll is True.
The difference between using poll() and poll2():
poll: All the read events are processed before the write events,
so the close after the first recv by TestHandler will be followed
by a send by TestClient within the same call to poll(). The
test is deterministic.
poll2: The order in which events are received is os dependent. So
it is possible that the first recv by TestHandler is the last
event in the 'r' list, so that after the close, a new call to
poll2() is done and the first event in this new 'r' list, is not
the expected write event for TestClient.
What about forcing self.use_poll to False, before calling
loop_waiting_for_flag() ? The drawback being that the test will be run
twice with the same environment.
|
msg146607 - (view) |
Author: Charles-François Natali (neologix) * |
Date: 2011-10-29 13:23 |
> The test fails when use_poll is True.
> The difference between using poll() and poll2():
poll uses select(2), while poll2 uses poll(2) (duh, that's confusing).
It seems that on OS X Snow Leopard, poll(2) sets the POLLPRI flag upon EPIPE (and probably doesn't return the FD in the exception set for select(2)...).
Not sure whether it's legal, but it's the only OS to do that (POLLPRI usually used for OOB data). Also, note that Tiger doesn't behave that way.
OS X often offers such surprises :-)
> What about forcing self.use_poll to False, before calling
> loop_waiting_for_flag() ? The drawback being that the test will be run
> twice with the same environment.
I just added an handle_expt() handler, and it works fine.
Closing, thanks for the patch!
|
|
Date |
User |
Action |
Args |
2022-04-11 14:56:47 | admin | set | github: 49911 |
2011-10-29 13:23:43 | neologix | set | status: open -> closed messages:
+ msg146607
assignee: josiahcarlson -> resolution: fixed stage: patch review -> resolved |
2011-10-29 12:27:20 | xdegaye | set | messages:
+ msg146606 |
2011-10-29 12:26:39 | python-dev | set | messages:
+ msg146605 |
2011-10-29 11:37:46 | neologix | set | messages:
+ msg146604 |
2011-10-29 10:42:48 | python-dev | set | nosy:
+ python-dev messages:
+ msg146602
|
2011-10-28 06:38:33 | neologix | set | messages:
+ msg146537 |
2011-10-27 18:37:30 | xdegaye | set | messages:
+ msg146514 |
2011-10-27 17:58:17 | neologix | set | nosy:
+ neologix messages:
+ msg146510
|
2011-10-27 14:42:15 | vstinner | set | nosy:
+ vstinner
|
2011-10-27 14:39:34 | xdegaye | set | files:
+ epipe-2.7.patch
messages:
+ msg146488 |
2011-10-27 14:38:04 | xdegaye | set | files:
+ epipe-default.patch
messages:
+ msg146487 |
2011-10-26 19:24:57 | xdegaye | set | files:
+ asyncore_epipe.py nosy:
+ xdegaye messages:
+ msg146452
|
2011-06-26 19:26:00 | terry.reedy | set | versions:
+ Python 3.2, Python 3.3, - Python 2.6, Python 3.0, Python 3.1 nosy:
+ stutzbach, terry.reedy, - josiah.carlson
messages:
+ msg139199
stage: patch review |
2009-04-02 01:19:40 | josiahcarlson | set | assignee: josiahcarlson messages:
+ msg85127 |
2009-04-02 01:03:25 | giampaolo.rodola | create | |