req.write can trigger spurious errors related to client disconnects

[Christian Boos]

A bit similar to #3957, but different place.

Traceback (most recent call last):
  File "/usr/local/virtualenv-0.11/lib/python2.5/site-packages/Trac-0.11.7stable_r8997-py2.5.egg/trac/web/main.py", line 450, in _dispatch_request
    dispatcher.dispatch(req)
  File "/usr/local/virtualenv-0.11/lib/python2.5/site-packages/Trac-0.11.7stable_r8997-py2.5.egg/trac/web/main.py", line 230, in dispatch
    req.send(output, content_type or 'text/html')
  File "/usr/local/virtualenv-0.11/lib/python2.5/site-packages/Trac-0.11.7stable_r8997-py2.5.egg/trac/web/api.py", line 359, in send
    self.write(content)
  File "/usr/local/virtualenv-0.11/lib/python2.5/site-packages/Trac-0.11.7stable_r8997-py2.5.egg/trac/web/api.py", line 463, in write
    self._write(data)
  File "/usr/local/virtualenv-0.11/lib/python2.5/site-packages/Trac-0.11.7stable_r8997-py2.5.egg/trac/web/_fcgi.py", line 1229, in write
    req.stdout.write(data)
  File "/usr/local/virtualenv-0.11/lib/python2.5/site-packages/Trac-0.11.7stable_r8997-py2.5.egg/trac/web/_fcgi.py", line 327, in write
    self._write(data)
  File "/usr/local/virtualenv-0.11/lib/python2.5/site-packages/Trac-0.11.7stable_r8997-py2.5.egg/trac/web/_fcgi.py", line 311, in _write
    self._conn.writeRecord(rec)
  File "/usr/local/virtualenv-0.11/lib/python2.5/site-packages/Trac-0.11.7stable_r8997-py2.5.egg/trac/web/_fcgi.py", line 709, in writeRecord
    rec.write(self._sock)
  File "/usr/local/virtualenv-0.11/lib/python2.5/site-packages/Trac-0.11.7stable_r8997-py2.5.egg/trac/web/_fcgi.py", line 542, in write
    self._sendall(sock, header)
  File "/usr/local/virtualenv-0.11/lib/python2.5/site-packages/Trac-0.11.7stable_r8997-py2.5.egg/trac/web/_fcgi.py", line 519, in _sendall
    sent = sock.send(data)
error: (32, 'Broken pipe')

2010-01-09 07:44:29,070 Trac[main] ERROR: Internal Server Error:
Traceback (most recent call last):
  File "/usr/local/virtualenv-0.11/lib/python2.5/site-packages/Trac-0.11.7stable_r8997-py2.5.egg/trac/web/main.py", line 450, in _dispatch_request
    dispatcher.dispatch(req)
  File "/usr/local/virtualenv-0.11/lib/python2.5/site-packages/Trac-0.11.7stable_r8997-py2.5.egg/trac/web/main.py", line 230, in dispatch
    req.send(output, content_type or 'text/html')
  File "/usr/local/virtualenv-0.11/lib/python2.5/site-packages/Trac-0.11.7stable_r8997-py2.5.egg/trac/web/api.py", line 359, in send
    self.write(content)
  File "/usr/local/virtualenv-0.11/lib/python2.5/site-packages/Trac-0.11.7stable_r8997-py2.5.egg/trac/web/api.py", line 463, in write
    self._write(data)
  File "/usr/local/virtualenv-0.11/lib/python2.5/site-packages/Trac-0.11.7stable_r8997-py2.5.egg/trac/web/_fcgi.py", line 1229, in write
    req.stdout.write(data)
  File "/usr/local/virtualenv-0.11/lib/python2.5/site-packages/Trac-0.11.7stable_r8997-py2.5.egg/trac/web/_fcgi.py", line 327, in write
    self._write(data)
  File "/usr/local/virtualenv-0.11/lib/python2.5/site-packages/Trac-0.11.7stable_r8997-py2.5.egg/trac/web/_fcgi.py", line 311, in _write
    self._conn.writeRecord(rec)
  File "/usr/local/virtualenv-0.11/lib/python2.5/site-packages/Trac-0.11.7stable_r8997-py2.5.egg/trac/web/_fcgi.py", line 709, in writeRecord
    rec.write(self._sock)
  File "/usr/local/virtualenv-0.11/lib/python2.5/site-packages/Trac-0.11.7stable_r8997-py2.5.egg/trac/web/_fcgi.py", line 542, in write
    self._sendall(sock, header)
  File "/usr/local/virtualenv-0.11/lib/python2.5/site-packages/Trac-0.11.7stable_r8997-py2.5.egg/trac/web/_fcgi.py", line 519, in _sendall
    sent = sock.send(data)
error: (104, 'Connection reset by peer')

0.12 version:

2010-03-02 10:32:17,183 Trac[main] ERROR: Internal Server Error:
Traceback (most recent call last):
  File "build/bdist.linux-x86_64/egg/trac/web/main.py", line 499, in _dispatch_request
    dispatcher.dispatch(req)
  File "build/bdist.linux-x86_64/egg/trac/web/main.py", line 256, in dispatch
    req.send(output, content_type or 'text/html')
  File "build/bdist.linux-x86_64/egg/trac/web/api.py", line 375, in send
    self.write(content)
  File "build/bdist.linux-x86_64/egg/trac/web/api.py", line 494, in write
    self._write(data)
  File "build/bdist.linux-x86_64/egg/trac/web/_fcgi.py", line 1229, in write
    req.stdout.write(data)
  File "build/bdist.linux-x86_64/egg/trac/web/_fcgi.py", line 327, in write
    self._write(data)
  File "build/bdist.linux-x86_64/egg/trac/web/_fcgi.py", line 311, in _write
    self._conn.writeRecord(rec)
  File "build/bdist.linux-x86_64/egg/trac/web/_fcgi.py", line 709, in writeRecord
    rec.write(self._sock)
  File "build/bdist.linux-x86_64/egg/trac/web/_fcgi.py", line 542, in write
    self._sendall(sock, header)
  File "build/bdist.linux-x86_64/egg/trac/web/_fcgi.py", line 520, in _sendall
    sent = sock.send(data)
error: (32, 'Broken pipe')

As discussed in ticket:9077#comment:4, point 1.

[Christian Boos]

trac/web/api.py

@@ -462 +462 @@
             self.end_headers()
         if isinstance(data, unicode):
             data = data.encode(self._outcharset or 'utf-8')
-        self._write(data)
+        try:
+            self._write(data)
+        except (IOError, socket.error), e:
+            if e.args[0] not in (errno.EPIPE, errno.ECONNRESET, 10053, 10054):
+                raise
 
     # Internal methods

Seems to work, more testing needed.

[Remy Blank]

Unfortunately, I cannot reproduce the issue with a browser, even without the patch. But I observe no difference in behavior with the patch applied, so it doesn't seem to have a negative effect.

But instead of swallowing the exception silently (as in the patch), and letting the request terminate "normally", shouldn't we rather abort the request by raising a RequestDone? The result of the request is unusable anyway, and subsequent calls to req.write() will raise the same exception again. Or do we risk skipping over wanted side-effects in the rest of the request?

[Christian Boos]

Replying to rblank:

But instead of swallowing the exception silently (as in the patch), and letting the request terminate "normally", shouldn't we rather abort the request by raising a RequestDone? The result of the request is unusable anyway, and subsequent calls to req.write() will raise the same exception again.

Yes, that was my follow-up questioning as well.

trac/web/api.py

@@ -326 +326 @@
         self.send_header('Cache-control', 'no-cache')
         self.send_header('Expires', 'Fri, 01 Jan 1999 00:00:00 GMT')
         self.end_headers()
-
         raise RequestDone
 
     def display(self, template, content_type='text/html', status=200):
@@ -465 +464 @@
         try:
             self._write(data)
         except (IOError, socket.error), e:
-            if e.args[0] not in (errno.EPIPE, errno.ECONNRESET, 10053, 10054):
-                raise
+            if e.args[0] in (errno.EPIPE, errno.ECONNRESET, 10053, 10054):
+                raise RequestDone
+            raise
 
     # Internal methods

Or do we risk skipping over wanted side-effects in the rest of the request?

I don't think so, as writing some content is usually the very last thing that happens, at the end of processing a request. And even if this would happen, I think that would fit with the "Cancel" semantic of an aborted read or a connection reset.

[Christian Boos]

Patch above committed as r9335.

[Christian Boos]

Argh, neither socket nor errno were imported here…

[Christian Boos]

Fixed in r9391, will be in patch release 0.11.7.1.

[Remy Blank]

Don't forget to backport it to 0.11-stable.

[Christian Boos]

Done in r9403, thanks for the reminder I had forgotten, indeed ;-)

[Thijs Triemstra <lists@…>]

Also ran into this one, switching to 0.11-stable.

[Christian Boos]

Replying to Thijs Triemstra <lists@…>:

Also ran into this one, switching to 0.11-stable.

What do you mean, r9403 was not enough? If that's the case, please post the full backtrace.