[PATCH] Handle disconnecting tracd clients more gracefully.

[pjd@…]

Currently, when a client disconnects unexpectedly, tracd prints a needlessly verbose traceback:

----------------------------------------
Exception happened during processing of request from ('1.2.3.4', 5678)
Traceback (most recent call last):
  File "/usr/local/lib/python2.4/SocketServer.py", line 463, in process_request_thread
    self.finish_request(request, client_address)
  File "/usr/local/lib/python2.4/SocketServer.py", line 254, in finish_request
    self.RequestHandlerClass(request, client_address, self)
  File "/usr/local/lib/python2.4/SocketServer.py", line 521, in __init__
    self.handle()
  File "/usr/local/lib/python2.4/BaseHTTPServer.py", line 314, in handle
    self.handle_one_request()
  File "/usr/local/lib/python2.4/BaseHTTPServer.py", line 308, in handle_one_request
    method()
  File "/usr/local/bin/tracd", line 227, in do_GET
    self.do_trac_req()
  File "/usr/local/bin/tracd", line 238, in do_trac_req
    trac.core.send_pretty_error(e, self.env, self)
  File "/usr/local/lib/python2.4/site-packages/trac/core.py", line 494, in send_pretty_error
    req.send_response(500)
  File "/usr/local/lib/python2.4/BaseHTTPServer.py", line 364, in send_response
    self.wfile.write("%s %d %s\r\n" %
  File "/usr/local/lib/python2.4/socket.py", line 256, in write
    self.flush()
  File "/usr/local/lib/python2.4/socket.py", line 243, in flush
    self._sock.sendall(buffer)
error: (32, 'Broken pipe')
----------------------------------------

With the following patch, tracd will log a short message instead, which is about all one can do in this situation.

--- tracd.orig  Tue Jan 18 13:26:40 2005
+++ tracd       Thu Feb  3 12:03:30 2005
@@ -32,6 +32,7 @@
 import shutil
 import getopt
 import locale
+import socket, errno
 import urllib
 import urllib2
 import mimetypes
@@ -235,7 +236,14 @@
         try:
             self.do_real_trac_req()
         except Exception, e:
-            trac.core.send_pretty_error(e, self.env, self)
+            try:
+                trac.core.send_pretty_error(e, self.env, self)
+            except socket.error, (code, msg):
+                if code == errno.EPIPE:
+                    self.log_message('Lost connection to client: %s', self.address_string())
+                else:
+                    raise

     def do_real_trac_req(self):
         start = time.time()

[Mark Rowe]

The patch below has been synced with trunk at r1502. It also handles the EPIPE that can occur during dispatch_request:

=== trac/web/standalone.py
==================================================================
--- trac/web/standalone.py  (revision 1281)
+++ trac/web/standalone.py  (local)
@@ -33,6 +33,7 @@
 import sys
 import md5
 import time
+import socket, errno
 import shutil
 import urllib
 import urllib2
@@ -245,8 +246,19 @@
             start = time.time()
             dispatch_request(path_info, req, env)
             self.log.debug('Total request time: %f s', time.time() - start)
+        except socket.error, (code, msg):
+            if code == errno.EPIPE:
+                self.log_message('Lost connection to client: %s', self.address_string())
+            else:
+                raise
         except Exception, e:
-            send_pretty_error(e, env, req)
+            try:
+                send_pretty_error(e, env, req)
+            except socket.error, (code, msg):
+                if code == errno.EPIPE:
+                    self.log_message('Lost connection to client: %s', self.address_string())
+                else:
+                    raise
 
 
 class TracHTTPRequest(Request):

[Christian Boos]

This one is even better at removing spurious stack traces, and works also on Windows.

It also fixes the long standing 'Conten-Length' misspelling!

trac/web/standalone.py

@@ -33 +33 @@
 import sys
 import md5
 import time
+import socket, errno
 import shutil
 import urllib
 import urllib2
@@ -192 +193 @@
         except IOError:
             self.send_error(404, path)
             return
-        self.send_response(200)
-        mtype, enc = mimetypes.guess_type(filename)
-        stat = os.fstat(f.fileno())
-        content_length = stat[6]
-        last_modified = time.strftime("%a, %d %b %Y %H:%M:%S GMT",
-                                      time.gmtime(stat[8]))
-        self.send_header('Content-Type', mtype)
-        self.send_header('Conten-Length', str(content_length))
-        self.send_header('Last-Modified', last_modified)
-        self.end_headers()
-        shutil.copyfileobj(f, self.wfile)
-
+        try:
+            self.send_response(200)
+            mtype, enc = mimetypes.guess_type(filename)
+            stat = os.fstat(f.fileno())
+            content_length = stat[6]
+            last_modified = time.strftime("%a, %d %b %Y %H:%M:%S GMT",
+                                          time.gmtime(stat[8]))
+            self.send_header('Content-Type', mtype)
+            self.send_header('Content-Length', str(content_length))
+            self.send_header('Last-Modified', last_modified)
+            self.end_headers()
+            shutil.copyfileobj(f, self.wfile)
+        except socket.error, (code, msg):
+            if code == errno.EPIPE or code == 10053: # Windows
+                self.log_message('Lost connection to client: %s', self.address_string())
+            else:
+                raise
+
     def do_POST(self):
         self.do_trac_req()
 
@@ -245 +252 @@
             start = time.time()
             dispatch_request(path_info, req, env)
             self.log.debug('Total request time: %f s', time.time() - start)
+        except socket.error, (code, msg):
+            if code == errno.EPIPE or code == 10053: # Windows
+                self.log_message('Lost connection to client: %s', self.address_string())
+            else:
+                raise
         except Exception, e:
-            send_pretty_error(e, env, req)
+            try:
+                send_pretty_error(e, env, req)
+            except socket.error, (code, msg):
+                if code == errno.EPIPE or code == 10053: # Windows
+                    self.log_message('Lost connection to client: %s', self.address_string())
+                else:
+                    raise
 
 
 class TracHTTPRequest(Request):

Should I commit it?

[Mark Rowe]

Sure. I was also wondering if this patch helped make tracd more stable for you in relation to #1401?

[Christian Boos]

I committed it [1503].

I also hoped it would help for #1401, but unfortunately it didn't help (it still crashes even on Linux).

[Christian Boos]

Was 0.9, but looks like the WSGI changes got rid of this…

Exception happened during processing of request from ('127.0.0.1', 2939)
Traceback (most recent call last):
  File "C:\Program Files\ActiveState\Python-2.4\lib\SocketServer.py", line 463, in process_request_thread
    self.finish_request(request, client_address)
  File "C:\Program Files\ActiveState\Python-2.4\lib\SocketServer.py", line 254, in finish_request
    self.RequestHandlerClass(request, client_address, self)
  File "C:\Program Files\ActiveState\Python-2.4\lib\SocketServer.py", line 521, in __init__
    self.handle()
  File "C:\Program Files\ActiveState\Python-2.4\lib\BaseHTTPServer.py", line 316, in handle
    self.handle_one_request()
  File "C:\Workspace\src\trac\branches\0.10-stable\trac\web\wsgi.py", line 174, in handle_one_request
    gateway.run(self.server.application)
  File "C:\Workspace\src\trac\branches\0.10-stable\trac\web\wsgi.py", line 95, in run
    self._write(chunk)
  File "C:\Workspace\src\trac\branches\0.10-stable\trac\web\wsgi.py", line 195, in _write
    self.handler.send_response(int(status[:3]))
  File "C:\Program Files\ActiveState\Python-2.4\lib\BaseHTTPServer.py", line 370, in send_response
    self.send_header('Server', self.version_string())
  File "C:\Program Files\ActiveState\Python-2.4\lib\BaseHTTPServer.py", line 377, in send_header
    self.wfile.write("%s: %s\r\n" % (keyword, value))
  File "C:\Program Files\ActiveState\Python-2.4\lib\socket.py", line 256, in write
    self.flush()
  File "C:\Program Files\ActiveState\Python-2.4\lib\socket.py", line 243, in flush
127.0.0.1 - - [08/Jan/2007 10:05:04] "GET /devel/timeline HTTP/1.1" 200 -
    self._sock.sendall(buffer)
error: (10053, 'Software caused connection abort')

(the above with 0.10.4dev)

[Christian Boos]

Reimplement silencing of connection interrupted errors in the request dispatcher

[Christian Boos]

In attachment:trap_connection_interrupted-r4510.diff​, I did this error catching in trac/web/main.py, as doing it in wsgi.py didn't work reliably.

Doing:

trac/web/wsgi.py

@@ -171 +171 @@
     def handle_one_request(self):
         environ = self.setup_environ()
         gateway = self.server.gateway(self, environ)
-        gateway.run(self.server.application)
+        import errno, socket
+        try:
+            gateway.run(self.server.application)
+        except socket.error, (code, msg):
+            if code == errno.EPIPE or code == 10053: # Windows
+                pass
+            else:
+                raise
 
     def finish(self):
         """We need to help the garbage collector a little."""

didn't prevent the following kind of exception:

Traceback (most recent call last):
  File "C:\Workspace\src\trac\trunk\trac\web\main.py", line 395, in dispatch_request
    dispatcher.dispatch(req)
  File "C:\Workspace\src\trac\trunk\trac\web\main.py", line 231, in dispatch
    req.send(output, content_type or 'text/html')
  File "C:\Workspace\src\trac\trunk\trac\web\api.py", line 313, in send
    self.write(content)
  File "C:\Workspace\src\trac\trunk\trac\web\api.py", line 410, in write
    self._write(data)
  File "C:\Workspace\src\trac\trunk\trac\web\wsgi.py", line 202, in _write
    self.handler.send_response(int(status[:3]))
  File "C:\Program Files\ActiveState\Python-2.4\lib\BaseHTTPServer.py", line 370, in send_response
    self.send_header('Server', self.version_string())
  File "C:\Program Files\ActiveState\Python-2.4\lib\BaseHTTPServer.py", line 377, in send_header
    self.wfile.write("%s: %s\r\n" % (keyword, value))
  File "C:\Program Files\ActiveState\Python-2.4\lib\socket.py", line 256, in write
    self.flush()
  File "C:\Program Files\ActiveState\Python-2.4\lib\socket.py", line 243, in flush
    self._sock.sendall(buffer)
error: (10053, 'Software caused connection abort')

By the way, while testing this patch, I've noticed it's quite easy to "saturate" tracd and have all the db connections in use; new requests are then blocking on the pool lock and after a while the timeout exception is raised. This is a separate issue, though, but easy to reproduce when you keep the "F5" key down ;)

[Christian Boos]

Replying to cboos:

… I've noticed it's quite easy to "saturate" tracd and have all the db connections in use; new requests are then blocking on the pool lock and after a while the timeout exception is raised. This is a separate issue, though, but easy to reproduce when you keep the "F5" key down ;)

r6261 seems to have fixed that.

[Christian Boos]

Move high prio tickets from 0.11-retriage to next maintenance release.

[Christian Boos]

Fixed in r8080. Before writing to the client, we first check if the file object is not already closed.

[Christian Boos]

Note that the fix doesn't work with Python 2.3 (see r8128).

[Christian Boos]

Please stop messing with this server, thanks.

[Christian Boos]

See also #8582.

[Christian Boos]

And #11049.