unhandled exception - socket

[james@…]

can we handle this appropriately?

Unhandled exception in thread started by <bound method Connection.run of <trac.web._fcgi.Connection object at 0xbe0757ec>>
Traceback (most recent call last):
  File "/usr/local/lib/python2.4/site-packages/trac/web/_fcgi.py", line 654, in run
    self.process_input()
  File "/usr/local/lib/python2.4/site-packages/trac/web/_fcgi.py", line 690, in process_input
    self._do_params(rec)
  File "/usr/local/lib/python2.4/site-packages/trac/web/_fcgi.py", line 789, in _do_params
    self._start_request(req)
  File "/usr/local/lib/python2.4/site-packages/trac/web/_fcgi.py", line 773, in _start_request
    req.run()
  File "/usr/local/lib/python2.4/site-packages/trac/web/_fcgi.py", line 582, in run
    self._flush()
  File "/usr/local/lib/python2.4/site-packages/trac/web/_fcgi.py", line 589, in _flush
    self.stdout.close()
  File "/usr/local/lib/python2.4/site-packages/trac/web/_fcgi.py", line 348, in close
    self._conn.writeRecord(rec)
  File "/usr/local/lib/python2.4/site-packages/trac/web/_fcgi.py", line 705, in writeRecord
    rec.write(self._sock)
  File "/usr/local/lib/python2.4/site-packages/trac/web/_fcgi.py", line 542, in write
    self._sendall(sock, header)
  File "/usr/local/lib/python2.4/site-packages/trac/web/_fcgi.py", line 519, in _sendall
    sent = sock.send(data)
socket.error: (32, 'Broken pipe')

[Jonas Borgström]

Can you give some brief instructions on how to reproduce this?

[wkornewald]

From what I've read this bug can be caused by a timed out MySQL connection. Maybe we could catch this exception and reconnect the DB when it happens? At least, I saw in a mailing list post that Rails' ActiveRecord is handling the exception that way.

It seems that this bug is related to #3369 and #3868. We're experiencing it on a shared host with Apache, FastCGI, and MySQL. Switching to sqlite is not a real option because our user login data is stored in a MySQL DB and I'm missing nice tools like phpmyadmin.

Could you please have a look at this bug? It's really annoying because sometimes pages aren't displayed, at all. Sometimes even reloading after that error fails. It also happens that I get an HTTP 500 error.

I'll also contact my hosting provider and ask whether they could update FastCGI (in case they are using an old version). Maybe that helps…

[wkornewald <wkornewald@…>]

Interesting articles: ​http://chris.gaskett.com/articles/rails-keeping-fastcgi-alive/ ​http://work.alexyoung.org/archives/102/dreamhost-and-rails-500-errors

More info from DreamHost (Rails-specific, but maybe useful):

If you are using fcgi with Ruby on Rails, you might get what appear to be random 500 errors occasionally. Alex Young's workaround (​http://work.alexyoung.org/archives/102/dreamhost-and-rails-500-errors), adapted from Gary Lin's workaround (​http://thread.gmane.org/gmane.comp.lang.ruby.rails/33057) seems to resolve this. Basically, add the following code to your dispatch.fcgi, right before RailsFCGIHandler.process!

class RailsFCGIHandler private

def frao_handler(signal)

dispatcher_log :info, "asked to terminate immediately" dispatcher_log :info, "frao handler working its magic!" restart_handler(signal)

end alias_method :exit_now_handler, :frao_handler

end

[Christian Boos]

Reformatting the Ruby code snippet from above:

class RailsFCGIHandler
  private
    def frao_handler(signal)
      dispatcher_log :info, "asked to terminate immediately"
      dispatcher_log :info, "frao handler working its magic!"
      restart_handler(signal)
    end
    alias_method :exit_now_handler, :frao_handler
end

[wkornewald]

Maybe this Apache log is helpful (esp. the two errors):

[Wed Nov 29 00:29:35 2006] [warn] FastCGI: (dynamic) server "/home/user/public_html/trac" (pid 16594) termination signaled
[Wed Nov 29 00:29:36 2006] [warn] FastCGI: (dynamic) server "/home/user/public_html/trac" (pid 16594) terminated by calling exit with status '0'
[Wed Nov 29 00:30:36 2006] [warn] FastCGI: scheduled the restart of the last (dynamic) server "/home/user/public_html/trac" process: reached dynamicMaxClassProcs (5)
[Wed Nov 29 00:30:36 2006] [warn] FastCGI: (dynamic) server "/home/user/public_html/trac" (uid 32005, gid 32008) restarted (pid 19715)
[Wed Nov 29 00:34:38 2006] [warn] FastCGI: (dynamic) server "/home/user/public_html/trac" (pid 19715) termination signaled
[Wed Nov 29 00:34:38 2006] [error] [client 217.12.250.67] (104)Connection reset by peer: FastCGI: comm with server "/home/user/public_html/trac" aborted: read failed
[Wed Nov 29 00:34:38 2006] [warn] FastCGI: (dynamic) server "/home/user/public_html/trac" (pid 19715) terminated by calling exit with status '0'
[Wed Nov 29 00:34:38 2006] [error] [client 217.12.250.67] FastCGI: incomplete headers (0 bytes) received from server "/home/user/public_html/trac"
[Wed Nov 29 00:36:00 2006] [warn] FastCGI: scheduled the restart of the last (dynamic) server "/home/user/public_html/trac" process: reached dynamicMaxClassProcs (5)

We're on a shared host (with MySQL and Trac 0.10.3dev) and we are only allowed to run five fcgi processes. For some reason, Trac is running about 8-12 processes the whole time. Sometimes this prevents me from doing anything at the shell (-bash: fork: Resource temporarily unavailable).

Could it be possible that Trac is not handling the exit signal correctly?

[Daniel Schiffner]

at me it looks like this:

Unhandled exception in thread started by <bound method Connection.run of <trac.web._fcgi.Connection object at 0xf577d06c>>
Traceback (most recent call last):
  File "/var/lib/python-support/python2.4/trac/web/_fcgi.py", line 654, in run
    self.process_input()
  File "/var/lib/python-support/python2.4/trac/web/_fcgi.py", line 690, in process_input
    self._do_params(rec)
  File "/var/lib/python-support/python2.4/trac/web/_fcgi.py", line 789, in _do_params
    self._start_request(req)
  File "/var/lib/python-support/python2.4/trac/web/_fcgi.py", line 773, in _start_request
    req.run()
  File "/var/lib/python-support/python2.4/trac/web/_fcgi.py", line 582, in run
    self._flush()
  File "/var/lib/python-support/python2.4/trac/web/_fcgi.py", line 589, in _flush
    self.stdout.close()
  File "/var/lib/python-support/python2.4/trac/web/_fcgi.py", line 348, in close
    self._conn.writeRecord(rec)
  File "/var/lib/python-support/python2.4/trac/web/_fcgi.py", line 705, in writeRecord
    rec.write(self._sock)
  File "/var/lib/python-support/python2.4/trac/web/_fcgi.py", line 542, in write
    self._sendall(sock, header)
  File "/var/lib/python-support/python2.4/trac/web/_fcgi.py", line 519, in _sendall
    sent = sock.send(data)
socket.error: (32, 'Daten\xfcbergabe unterbrochen (broken pipe)')

[TWCore.org]

I have the exact same problem, getting the following errors in the error log:

[Tue Feb 27 04:18:03 2007] [error] [client 66.249.65.201] FastCGI: comm with (dynamic) server "/home/twcore/twcore.org/index.fcgi" aborted: (first read) idle timeout (60 sec)
[Tue Feb 27 04:18:03 2007] [error] [client 66.249.65.201] FastCGI: incomplete headers (0 bytes) received from server "/home/twcore/twcore.org/index.fcgi"
[Tue Feb 27 04:18:03 2007] [error] [client 66.249.65.201] File does not exist: /home/twcore/twcore.org/internal_error.html

Does anyone know how this can be solved?

[Christian Boos]

(moving to 0.10.x along with other fastcgi tickets)

[anonymous]

As far as I know, this isn't an issue in flup 1.0. As in, it at the very least doesn't print out that error, which in my experience happens when an HTTP request is interrupted. I don't know why it happens with Trac.

But why was flup copied and pasted into Trac anyway? Can't you just declare it as a dependency in setup.py and import it?

[Emmanuel Blot]

#4976 marked has a duplicate

[erose]

I get this in my FastCGI/SQLite setup, FWIW.

[Jonas Borgström]

Moving this to 0.11.2 since this "only" results in excessive logging and does no failures.

[Christian Boos]

Replying to anonymous:

As far as I know, this isn't an issue in flup 1.0. … But why was flup copied and pasted into Trac anyway?

No idea, but eventually we could integrate a more recent version (​http://www.saddi.com/software/flup/dist/). A superficial look to 1.0 shows that it's not 2.3 compatible anymore, so I'll tentatively target 0.12.

[Remy Blank]

Am I right to assume that flup is the _fcgi.py module? The current version has a small bug described in #7239.

[Christian Boos]

Yes, trac/web/_fcgi.py correspond to flup's client/fcgi_app.py, and last update was done in r3677. So "our" _fcgi.py is based on upstream r2025, and the 1.0 version discussed above corresponds to the newer r2109 (which is apparently not brand new either).

[Christian Boos]

Looking again at the _fcgi.py code, I see that r3677 actually removed the special case for E.PIPE. Maybe we can just add it back?

[Remy Blank]

Not a blocker.

[Christian Boos]

Seen that in t.e.o logs as well. Will fix it by applying upstream fix.

[Christian Boos]

Fixed in [8820].

[Christian Boos]

I also see this error now:

Traceback (most recent call last):
  File "/usr/local/virtualenv/lib/python2.5/site-packages/Trac-0.11.6stable_r8820-py2.5.egg/trac/web/_fcgi.py", line 661, in run
    except (select.error, socket.error), e:
AttributeError: 'NoneType' object has no attribute 'error'

Not sure if it's related to r8820 though.

[Christian Boos]

Another backtrace, similar to the original one:

Traceback (most recent call last):
  File ".../trac/web/_fcgi.py", line 658, in run
    self.process_input()
  File ".../trac/web/_fcgi.py", line 694, in process_input
    self._do_params(rec)
  File ".../trac/web/_fcgi.py", line 793, in _do_params
    self._start_request(req)
  File ".../trac/web/_fcgi.py", line 777, in _start_request
    req.run()
  File ".../trac/web/_fcgi.py", line 573, in run
    self.stderr.flush()
  File ".../trac/web/_fcgi.py", line 340, in flush
    self._write(data)
  File ".../trac/web/_fcgi.py", line 311, in _write
    self._conn.writeRecord(rec)
  File ".../trac/web/_fcgi.py", line 709, in writeRecord
    rec.write(self._sock)
  File ".../trac/web/_fcgi.py", line 542, in write
    self._sendall(sock, header)
  File ".../trac/web/_fcgi.py", line 519, in _sendall
    sent = sock.send(data)

[Christian Boos]

Also got this, while terminating tracd:

Unhandled exception in thread started by <function serve at 0x02DC74F0>
Traceback (most recent call last):
  File "trac/web/standalone.py", line 268, in serve
    httpd.serve_forever()
  File "C:\Dev\Python261\lib\SocketServer.py", line 224, in serve_forever
    r, w, e = select.select([self], [], [], poll_interval)
AttributeError: 'NoneType' object has no attribute 'select'

Which suggests that there's might be some kind of cleanup done for the select module (an atexit handler?).

[Remy Blank]

I observe the same traceback regularly since I switched to Python 2.6.

[Christian Boos]

Replying to rblank:

I observe the same traceback regularly since I switched to Python 2.6.

Sebastian Krysmanski also reported this today (#9960), still with 2.6.

[anonymous]

2018 calling… still seeing this on 0.12.5

Unhandled exception in thread started by <bound method Connection.run of <trac.web._fcgi.Connection object at 0x37d7610>>
Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/trac/web/_fcgi.py", line 658, in run
    self.process_input()
  File "/usr/lib/python2.7/dist-packages/trac/web/_fcgi.py", line 694, in process_input
    self._do_params(rec)
  File "/usr/lib/python2.7/dist-packages/trac/web/_fcgi.py", line 793, in _do_params
    self._start_request(req)
  File "/usr/lib/python2.7/dist-packages/trac/web/_fcgi.py", line 777, in _start_request
    req.run()
  File "/usr/lib/python2.7/dist-packages/trac/web/_fcgi.py", line 584, in run
    self._end(appStatus, protocolStatus) 
  File "/usr/lib/python2.7/dist-packages/trac/web/_fcgi.py", line 590, in _end
    self._conn.end_request(self, appStatus, protocolStatus)
  File "/usr/lib/python2.7/dist-packages/trac/web/_fcgi.py", line 725, in end_request
    self.writeRecord(rec)
  File "/usr/lib/python2.7/dist-packages/trac/web/_fcgi.py", line 709, in writeRecord
    rec.write(self._sock)
  File "/usr/lib/python2.7/dist-packages/trac/web/_fcgi.py", line 542, in write
    self._sendall(sock, header)
  File "/usr/lib/python2.7/dist-packages/trac/web/_fcgi.py", line 520, in _sendall
    sent = sock.send(data)
socket.error: [Errno 104] Connection reset by peer

fastcgi.conf

<IfModule mod_fastcgi.c>
  AddHandler fastcgi-script .fcgi
  FastCgiIpcDir /var/lib/apache2/fastcgi
  FastCgiConfig -initial-env TRAC_ENV_PARENT_DIR=/var/www/vhosts/<redacted>/trac  \
                -initial-env PYTHON_EGG_CACHE=/var/www/egg_cache \
                -initial-env LC_TIME=en_AU.UTF-8 \
                -maxClassProcesses 60 -maxProcesses 150 -idle-timeout 300
</IfModule>

No mysql involved here.

[Jun Omae]

Replying to anonymous:

2018 calling… still seeing this on 0.12.5

socket.error: [Errno 104] Connection reset by peer

We should ignore errno.ECONNRESET also but 0.12-stable branch is no longer maintained. We recommend to upgrade to Trac 1.0.x, at least. If it is hard to upgrade, try to apply the following patch for 0.12-stable.

1.0-stable:

branches/1.0-stable/trac/web/_fcgi.py

@@ -62 +62 @@
 if not hasattr(socket, 'SHUT_WR'):
     socket.SHUT_WR = 1
 
+from trac.web.api import is_client_disconnect_exception
+
+
 __all__ = ['WSGIServer']
 
 # Constants from the spec.
@@ -583 +586 @@
             self._flush()
             self._end(appStatus, protocolStatus)
         except socket.error, e:
-            if e[0] != errno.EPIPE:
+            if not is_client_disconnect_exception(e):
                 raise
 
     def _end(self, appStatus=0L, protocolStatus=FCGI_REQUEST_COMPLETE):
@@ -1270 +1273 @@
                     if hasattr(result, 'close'):
                         result.close()
             except socket.error, e:
-                if e[0] != errno.EPIPE:
+                if not is_client_disconnect_exception(e):
                     raise # Don't let EPIPE propagate beyond server
         finally:
             if not self.multithreaded:

0.12-stable:

branches/0.12-stable/trac/web/_fcgi.py

@@ -583 +583 @@
             self._flush()
             self._end(appStatus, protocolStatus)
         except socket.error, e:
-            if e[0] != errno.EPIPE:
+            if e[0] not in (errno.EPIPE, errno.ECONNRESET):
                 raise
 
     def _end(self, appStatus=0L, protocolStatus=FCGI_REQUEST_COMPLETE):
@@ -1268 +1268 @@
                     if hasattr(result, 'close'):
                         result.close()
             except socket.error, e:
-                if e[0] != errno.EPIPE:
+                if e[0] not in (errno.EPIPE, errno.ECONNRESET):
                     raise # Don't let EPIPE propagate beyond server
         finally:
             if not self.multithreaded: