Re: Spurious 500 errors

jkuefler wrote:
>
> I'm getting spurious/intermittant HTTP-500 errors from a FastCGI app 
> and need to somehow get more information from FastCGI other than what 
> shows up in the apache log (which is not much).  I know it is not the 
> application crashing or giving back illegal headers.  It is the 
> communication between the FastCGI processes and the master FastCGI 
> controller (or whatever).
>
For what it's worth, there is no communication between the app and a 
"master controller".  The app has a socket open that the httpd processes 
use to communicate to the app.  The only thing the master process does 
is spawn children, reap them, and otherwise get out of the way.

Your error messages make it look like that socket communication breaks; 
either the write() from the app returns non-zero, or the read() in httpd 
returns non-zero.  You could try a truss/strace on one httpd, and limit 
it to the read/writes on the application FD to see what's happening 
there when it fails.  Might take a while to grab one, but at least you 
can then see what's breaking.

David.

------------------------------------------------------------------------

> My app has been up and deployed for several weeks and has handled a 
> fair number of concurrent users.  But today starting around 5:30pm, it 
> started handing out random 500 errors.  Oddly enough, apache was 
> bounced at around 4:00pm, ruling OUT that my persistent processes were 
> somehow stuck (memory leaks or whatever).
>
> Out of 17,831 requests today, 44 resulted in 500 errors.  That may not 
> seem like a lot, but that means 44 user-visible things broken in the 
> browser (they entire page or an ajax component showing up with the 500 
> error screen of death).
>
> Although I can reproduce it fairly quickly, there is no telling which 
> request will give back a 500 error (it is not consistent).  According 
> to the apache log, the FastCGI exes are return NOTHING ("0 bytes"), 
> which results in a 500, since even an empty web page needs a properly 
> formed http header.
>
> Here is an actual apache log extract showing 500 errors interspersed 
> with normal requests.  Note that I send the apache access and error 
> log output to the same file which helps this type of debugging:
>
>       [Tue Oct 16 22:06:14 2007] [error] [client 192.168.101.205]
>       (32)Broken pipe: FastCGI: comm with server
>       "/usr/local/packages/v1/linux/v.fcgi" aborted: write failed
>
>       [Tue Oct 16 22:06:14 2007] [error] [client 192.168.101.205]
>       FastCGI: incomplete headers (0 bytes) received from server
>       "/usr/local/packages/v1/linux/v.fcgi"
>
>       192.168.101.205 - mhagerty [16/Oct/2007:22:06:10 -0400] "GET
>       /tdc/v HTTP/1.1" 500 714
>       [Tue Oct 16 22:08:11 2007] [error] [client 192.168.101.205]
>       (32)Broken pipe: FastCGI: comm with server
>       "/usr/local/packages/v1/linux/v.fcgi" aborted: write failed
>
>       [Tue Oct 16 22:08:11 2007] [error] [client 192.168.101.205]
>       FastCGI: incomplete headers (0 bytes) received from server
>       "/usr/local/packages/v1/linux/v.fcgi"
>
>       192.168.101.205 - mhagerty [16/Oct/2007:22:08:07 -0400] "GET
>       /tdc/v HTTP/1.1" 500 714
>       aries.tpnyc.local - - [16/Oct/2007:22:08:24 -0400] "GET /tpt/v
>       HTTP/1.1" 401 576
>       aries.tpnyc.local - hnarin [16/Oct/2007:22:08:36 -0400] "GET
>       /tpt/v HTTP/1.1" 200 20108
>       aries.tpnyc.local - hnarin [16/Oct/2007:22:08:37 -0400] "GET
>       /tpt/all-min.js HTTP/1.1" 304 -
>       aries.tpnyc.local - hnarin [16/Oct/2007:22:08:37 -0400] "GET
>       /tpt/skin-gl/ktab.css HTTP/1.1" 304 -
>       aries.tpnyc.local - hnarin [16/Oct/2007:22:08:37 -0400] "GET
>       /tpt/skin-gl/vencore.css HTTP/1.1" 304 -
>       aries.tpnyc.local - hnarin [16/Oct/2007:22:08:37 -0400] "GET
>       /tpt/skin-gl/vencore-ie.css HTTP/1.1" 304 -
>       192.168.101.205 - - [16/Oct/2007:22:08:36 -0400] "GET /tpt/v
>       HTTP/1.1" 401 577
>       [Tue Oct 16 22:08:53 2007] [error] [client 192.168.101.205]
>       (32)Broken pipe: FastCGI: comm with server
>       "/usr/local/packages/v1/linux/v.fcgi" aborted: write failed
>
>       [Tue Oct 16 22:08:53 2007] [error] [client 192.168.101.205]
>       FastCGI: incomplete headers (0 bytes) received from server
>       "/usr/local/packages/v1/linux/v.fcgi"
>
>       192.168.101.205 - jkuefler [16/Oct/2007:22:08:49 -0400] "GET
>       /tpt/v HTTP/1.1" 500 714
>
> As far as tuning FastCGI, I am currently starting 30 processes with a 
> queue depth of 100.  Here are all the relevant httpd.conf lines:
>
>       LoadModule fastcgi_module     modules/mod_fastcgi240_apache20.so
>       AddHandler fastcgi-script     fcgi
>       FastCgiServer /usr/local/packages/v1/linux/v.fcgi -processes 30
>       -listen-queue-depth 200
>       ScriptAlias /tpt/v     "/usr/local/packages/v1/linux/v.fcgi"
>       ScriptAlias /tdc/v     "/usr/local/packages/v1/linux/v.fcgi"
>
> I find it hard to believe that 30 processes is not enough, nor that 
> the queue depth is too shallow.  The problem started occurring at 
> off-peak hours (thankfully).  The machine is beefy: 2 GB RAM, 4 CPUs, 
> etc.  Apache runs in a VM (Suse Linux) and the host operating system 
> is XP.
>
> Any insight and/or way to get MORE INFORMATION out of FastCGI is 
> deeply appreciated.
>
> Thanks,
>    jkuefler at translations dot com
>
>
> ------------------------------------------------------------------------
>
> ___________________________________
> fastcgi-developers mailing list
> http://fastcgi.com/fastcgi-developers/
>

___________________________________
fastcgi-developers mailing list
http://fastcgi.com/fastcgi-developers/