classification
Title: SocketServer doesn't handle client disconnects properly
Type: Stage: committed/rejected
Components: Library (Lib) Versions: Python 3.4, Python 3.3, Python 3.2, Python 2.7
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: Nosy List: asvetlov, kristjan.jonsson, mikeputnam, neologix, pitrou, python-dev, vdjeric
Priority: normal Keywords: patch

Created on 2012-04-13 23:07 by vdjeric, last changed 2012-12-26 19:26 by asvetlov. This issue is now closed.

Files
File name Uploaded Description Edit
socketserver.patch kristjan.jonsson, 2012-10-04 11:01 review
socketserver.patch kristjan.jonsson, 2012-10-05 10:53 review
Messages (19)
msg158240 - (view) Author: Vladan Djeric (vdjeric) Date: 2012-04-13 23:07
When dealing with a new connection, SocketServer.BaseRequestHandler.__init__ first calls the request handler (self.handle below) and then calls cleanup code which closes the connection (self.finish below).

class BaseRequestHandler:
    def __init__(self, request, client_address, server):
        < ... snip ... >
        try:
            self.handle()
        finally:
            self.finish()

The issue arises when a client disconnects suddenly during the self.handle() call. The handler may attempt to write data to the disconnected socket.  This will cause an exception (which is correct), but somehow data will still be added to the connection's buffer and self.wfile.closed will be False! As a result, BaseRequestHandler.finish() will attempt to flush the connection's buffer and this will raise another exception which can't be handled without modifying the library code.

----------------------------------------
Exception happened during processing of request from ('127.0.0.1', 62718)
Traceback (most recent call last):
  File "C:\Python27\lib\SocketServer.py", line 284, in _handle_request_noblock
    self.process_request(request, client_address)
  File "C:\Python27\lib\SocketServer.py", line 310, in process_request
    self.finish_request(request, client_address)
  File "C:\Python27\lib\SocketServer.py", line 323, in finish_request
    self.RequestHandlerClass(request, client_address, self)
  File "C:\Python27\lib\SocketServer.py", line 641, in __init__
    self.finish()
  File "C:\Python27\lib\SocketServer.py", line 694, in finish
    self.wfile.flush()
  File "C:\Python27\lib\socket.py", line 303, in flush
    self._sock.sendall(view[write_offset:write_offset+buffer_size])
error: [Errno 10053] An established connection was aborted by the software in your host machine
----------------------------------------

I've provided a toy server below, you can reproduce the issue by submitting a request to it with curl and then immediately killing curl:

 curl -d "test"  http://127.0.0.1:8000/

Toy server code:
===========================

import BaseHTTPServer
import SocketServer
import time

class ThreadedHTTPServer(BaseHTTPServer.HTTPServer):
  pass

class RequestHandler(BaseHTTPServer.BaseHTTPRequestHandler):
  def do_POST(self):
    try:
      length = int(self.headers["Content-Length"])
      request = self.rfile.read(length)

      print "Sleeping. Kill the 'curl' command now."
      time.sleep(10)
      print "Woke up. You should see a stack trace from the problematic exception below."

      print "Received POST: " + request
      self.send_response(200) # <------- This somehow adds to the connection's buffer!
      self.end_headers()
    except Exception as e:
      print "Exception: " + str(e)  # <----- This exception is expected

httpd = ThreadedHTTPServer(("127.0.0.1", 8000), RequestHandler)
httpd.serve_forever()
httpd.server_close()
msg158263 - (view) Author: Charles-François Natali (neologix) * (Python committer) Date: 2012-04-14 13:39
Thanks for the report.

Several things are going on here:
1. Even though socketserver's StreamRequestHandler uses unbuffered wfile for the socket
"""
class StreamRequestHandler(BaseRequestHandler):
    [...]
    rbufsize = -1
    wbufsize = 0

    # A timeout to apply to the request socket, if not None.
    timeout = None

    # Disable nagle algorithm for this socket, if True.
    # Use only when wbufsize != 0, to avoid small packets.
    disable_nagle_algorithm = False

    def setup(self):
        self.connection = self.request
        if self.timeout is not None:
            self.connection.settimeout(self.timeout)
        if self.disable_nagle_algorithm:
            self.connection.setsockopt(socket.IPPROTO_TCP,
                                       socket.TCP_NODELAY, True)
        self.rfile = self.connection.makefile('rb', self.rbufsize)
        self.wfile = self.connection.makefile('wb', self.wbufsize)
"""

data is internally buffered by socket._fileobject:
"""
    def write(self, data):
        data = str(data) # XXX Should really reject non-string non-buffers
        if not data:
            return
        self._wbuf.append(data)
        self._wbuf_len += len(data)
        if (self._wbufsize == 0 or
            self._wbufsize == 1 and '\n' in data or
            self._wbuf_len >= self._wbufsize):
            self.flush()
"""

Usually it doesn't turn out to be a problem because if the object is unbuffered the buffer is flushed right away, but in this specific case, it's a problem because a subsequent call to flush() will try to drain the data buffered temporarily, which triggers the second EPIPE from the StreamRequestHandler.finish()
Note that Python 3.3 doesn't have this problem.
While this is arguably a bad behavior, I don't feel comfortable changing this in 2.7 (either by changing the write() and flush() method or by just checking that the _fileobject is indeed buffered before flushing it).
Moreover, this wouldn't solve the problem at hand in case the user chose  to use a buffered connection (StreamRequestHandler.wbufsize > 0).

2. I think the root cause of the problem is that the handler's finish() method is called even when an exception occured during the handler, in which case nothing can be assumed about the state of the connection:

"""
class BaseRequestHandler:
    [...]
        self.setup()
        try:
            self.handle()
        finally:
            self.finish()
"""

Which is funny, because it doesn't match the documentation:
"""
.. method:: RequestHandler.finish()

   Called after the :meth:`handle` method to perform any clean-up actions
   required.  The default implementation does nothing.  If :meth:`setup` or
   :meth:`handle` raise an exception, this function will not be called.
"""

So the obvious solution would be to change the code to match the documentation, and not call finish when an exception was raised.
But that would be a behavior change, and could introduce resource leaks.
For example, here's StreamRequestHandler finish() method:
"""
    def finish(self):
        if not self.wfile.closed:
            self.wfile.flush()
        self.wfile.close()
        self.rfile.close()
"""
While in this specific case if wouldn't lead to a FD leak (because the underlying socket is closed by the server code), one could imagine a case where it could have a negative impact, so I'm not sure about changing this.

Finally, you could get rid of this error by overriding StreamRequestHandler.finish() method or catching the first exception in the handle() method and close the connection explicitely.

So I'd like to know what others think about this :-)
msg158286 - (view) Author: Vladan Djeric (vdjeric) Date: 2012-04-14 21:37
Thank you for taking a look Charles-François.

I should note that catching the first exception in the request handler and then calling self.wfile.close() wouldn't fully solve the issue. The self.wfile.close() call would throw another broken pipe exception (which is ok & can be caught), but the BaseHTTPServer code would also throw an exception when it tries to flush the (now closed) wfile after returing from the do_POST request handler.

----------------------------------------
Exception happened during processing of request from ('127.0.0.1', 50611)
Traceback (most recent call last):
  File "C:\Python27\lib\SocketServer.py", line 284, in _handle_request_noblock
    self.process_request(request, client_address)
  File "C:\Python27\lib\SocketServer.py", line 310, in process_request
    self.finish_request(request, client_address)
  File "C:\Python27\lib\SocketServer.py", line 323, in finish_request
    self.RequestHandlerClass(request, client_address, self)
  File "C:\Python27\lib\SocketServer.py", line 638, in __init__
    self.handle()
  File "C:\Python27\lib\BaseHTTPServer.py", line 340, in handle
    self.handle_one_request()
  File "C:\Python27\lib\BaseHTTPServer.py", line 329, in handle_one_request
    self.wfile.flush() #actually send the response if not already done.
  File "C:\Python27\lib\socket.py", line 303, in flush
    self._sock.sendall(view[write_offset:write_offset+buffer_size])
AttributeError: 'NoneType' object has no attribute 'sendall'
----------------------------------------
msg158319 - (view) Author: Kristján Valur Jónsson (kristjan.jonsson) * (Python committer) Date: 2012-04-15 11:26
I think this needs serious consideration.  There needs to be an "socket error" case cleanup path that releases resources but ignores further socket errors.
msg171932 - (view) Author: Kristján Valur Jónsson (kristjan.jonsson) * (Python committer) Date: 2012-10-04 10:48
Clearly, the finish call is intended to be called, and I think the documentation is in error.
However, the finish call should also be able to cope with the connection having been reset and handle such errors as may occur.
msg171933 - (view) Author: Kristján Valur Jónsson (kristjan.jonsson) * (Python committer) Date: 2012-10-04 11:01
Please consider the attached patch and see if it solves the issue.
msg171998 - (view) Author: Charles-François Natali (neologix) * (Python committer) Date: 2012-10-04 21:40
> Please consider the attached patch and see if it solves the issue.

The patch looks OK (although I'd prefer a BSD errno example, such as
ECONNRESET, instead of a winsock one).

We should also update the documentation that states that in finish()
won't be called if handle() raises an exception.
msg172072 - (view) Author: Kristján Valur Jónsson (kristjan.jonsson) * (Python committer) Date: 2012-10-05 10:53
> although I'd prefer a BSD errno example, such as ECONNRESET, instead of a winsock one
Are you referring to the comment where I mention ECONNABORTED?  That is a regular unix error (windows version is WSAECONNABORTED).
This error occurs when the local stack decides to kill the connection, as opposed to ECONNRESET which occurs on account of receiving a RST packet.

New patch includes documentation change.

If 2.7 is still in bugfix mode, then this patch could probably be accepted.
msg172116 - (view) Author: Charles-François Natali (neologix) * (Python committer) Date: 2012-10-05 19:16
> Are you referring to the comment where I mention ECONNABORTED?  That is a regular unix error (windows version is WSAECONNABORTED).
> This error occurs when the local stack decides to kill the connection, as opposed to ECONNRESET which occurs on account of receiving a RST packet.

Oops, I misread. ECONNABORTED is fine.

> New patch includes documentation change.

LGTM.

> If 2.7 is still in bugfix mode, then this patch could probably be accepted.

I guess so.
msg178124 - (view) Author: Kristján Valur Jónsson (kristjan.jonsson) * (Python committer) Date: 2012-12-25 13:11
So, should I commit this?  The change is really trivial.
msg178161 - (view) Author: Charles-François Natali (neologix) * (Python committer) Date: 2012-12-25 19:36
> So, should I commit this?  The change is really trivial.

LGTM.
This should be applied to 2.7.
msg178168 - (view) Author: Roundup Robot (python-dev) Date: 2012-12-25 22:47
New changeset df51cb946d27 by Kristján Valur Jónsson in branch '2.7':
Issue #14574: Ignore socket errors raised when flushing a connection on close.
http://hg.python.org/cpython/rev/df51cb946d27
msg178169 - (view) Author: Andrew Svetlov (asvetlov) * (Python committer) Date: 2012-12-25 22:52
Not clean to me: has python3 the same bug?
msg178178 - (view) Author: Kristján Valur Jónsson (kristjan.jonsson) * (Python committer) Date: 2012-12-26 00:50
Semantically, but I am told that due to py3k's different file buffering, that those errors don't percolate through. According to Charles-Francois' post from apr, 14th:
"Note that Python 3.3 doesn't have this problem."
msg178194 - (view) Author: Charles-François Natali (neologix) * (Python committer) Date: 2012-12-26 09:42
> Semantically, but I am told that due to py3k's different file buffering, that those errors don't percolate through. According to Charles-Francois' post from apr, 14th:
> "Note that Python 3.3 doesn't have this problem."

It's not affected by the problem, but it's really just accidental, so
it would probably be better to apply this as well to py3k.
msg178200 - (view) Author: Kristján Valur Jónsson (kristjan.jonsson) * (Python committer) Date: 2012-12-26 11:07
Ok, I'll have a look.
msg178225 - (view) Author: Roundup Robot (python-dev) Date: 2012-12-26 15:30
New changeset 7e5d7ef4634d by Kristján Valur Jónsson in branch '3.2':
Issue #14574: Ignore socket errors raised when flushing a connection on close.
http://hg.python.org/cpython/rev/7e5d7ef4634d

New changeset 7734c3020a47 by Kristján Valur Jónsson in branch '3.3':
Merge with 3.2 :
http://hg.python.org/cpython/rev/7734c3020a47

New changeset 2d1cfbaef9a2 by Kristján Valur Jónsson in branch 'default':
Merge with 3.3
http://hg.python.org/cpython/rev/2d1cfbaef9a2
msg178226 - (view) Author: Kristján Valur Jónsson (kristjan.jonsson) * (Python committer) Date: 2012-12-26 15:33
There, applied the same changes to the 3.x branches.
apparently the DOC folder wasn't branched off for 3.3, or something, at least, there is no sepatate 3.3 and 'default' version of socketserver.rst.  Or maybe it is just Hg that got the better of me.
msg178238 - (view) Author: Andrew Svetlov (asvetlov) * (Python committer) Date: 2012-12-26 19:26
Everything is fine. Close the issue.
History
Date User Action Args
2012-12-26 19:26:45asvetlovsetstatus: open -> closed

messages: + msg178238
stage: committed/rejected
2012-12-26 15:33:01kristjan.jonssonsetmessages: + msg178226
2012-12-26 15:30:27python-devsetmessages: + msg178225
2012-12-26 15:05:01kristjan.jonssonsetversions: + Python 3.2, Python 3.3, Python 3.4
2012-12-26 11:07:24kristjan.jonssonsetmessages: + msg178200
2012-12-26 09:42:15neologixsetmessages: + msg178194
2012-12-26 00:50:54kristjan.jonssonsetmessages: + msg178178
2012-12-25 22:52:21asvetlovsetnosy: + asvetlov
messages: + msg178169
2012-12-25 22:47:31kristjan.jonssonsetresolution: fixed
2012-12-25 22:47:03python-devsetnosy: + python-dev
messages: + msg178168
2012-12-25 19:36:27neologixsetmessages: + msg178161
2012-12-25 13:11:05kristjan.jonssonsetmessages: + msg178124
2012-10-05 19:16:10neologixsetmessages: + msg172116
2012-10-05 10:53:43kristjan.jonssonsetfiles: + socketserver.patch

messages: + msg172072
2012-10-04 21:40:37neologixsetmessages: + msg171998
2012-10-04 11:01:53kristjan.jonssonsetfiles: + socketserver.patch
keywords: + patch
messages: + msg171933
2012-10-04 10:48:26kristjan.jonssonsetmessages: + msg171932
2012-10-03 18:57:13mikeputnamsetnosy: + mikeputnam
2012-04-15 11:26:06kristjan.jonssonsetmessages: + msg158319
2012-04-14 21:37:24vdjericsetmessages: + msg158286
2012-04-14 13:39:42neologixsetnosy: + pitrou
messages: + msg158263
2012-04-14 11:25:20pitrousetnosy: + neologix
2012-04-14 10:10:50kristjan.jonssonsetnosy: + kristjan.jonsson
2012-04-13 23:07:42vdjericcreate