fcgi timeout trouble

ygrek <[email protected]> Tue, 15 Sep 2009 21:53:55 +0300
Newsgroups gmane.comp.lang.ocaml.lib.net.devel
Message-ID <[email protected]>
Hello,

 I have a problem with ocamlnet fcgi and nginx on Linux. I am not sure
which side is to blame, but maybe you can give me some advice.

Consider the following scenario :

----- Code
$ cat fcgi.ml
let addr = Unix.inet_addr_loopback
 
let reply (cgi:Netcgi_fcgi.cgi) =
  cgi#set_header ~cache:`No_cache ~content_type:"text/plain" ();
  cgi#out_channel#output_string "Hello, world!";
  Thread.delay 30.;
  cgi#out_channel#commit_work ()
 
let listen () =
  let buffered _ ch = new Netchannels.buffered_trans_channel ch in
  Netcgi_fcgi.run ~output_type:(`Transactional buffered)
    ~sockaddr:(Unix.ADDR_INET(addr, 10000))
    reply
 
let () =
  listen ()

---- Nginx setup
$ cat /etc/nginx/sites-enabled/test 

server {
	listen   8001;
	server_name  localhost;

	access_log  /var/log/nginx/test.access.log;

	location / {
    fastcgi_pass 127.0.0.1:10000;
    include fastcgi_params;
  }
}

---- Compile
$ ocamlfind ocamlopt -thread -linkpkg -package threads,netcgi2 fcgi.ml -o fcgi

---- Start fcgi and nginx
$ strace ./fcgi
$ sudo invoke-rc.d nginx start

---- Make some requests
$ siege -b -c 20 -t30s localhost:8001

---- Wait until siege finishes. Because of timeout in fcgi it will report zero hits - it is ok.
---- Now periodically watch active tcp connections
$ sudo netstat -tpn | grep 10000
tcp        0      0 127.0.0.1:10000         127.0.0.1:56169         SYN_RECV    -               
tcp        0      0 127.0.0.1:10000         127.0.0.1:56171         SYN_RECV    -               
tcp        0      0 127.0.0.1:10000         127.0.0.1:56161         SYN_RECV    -               
tcp        0      0 127.0.0.1:10000         127.0.0.1:56173         SYN_RECV    -               
tcp        0      0 127.0.0.1:10000         127.0.0.1:56155         CLOSE_WAIT  2024/fcgi       
tcp      529      0 127.0.0.1:10000         127.0.0.1:56165         CLOSE_WAIT  -               
tcp        0      0 127.0.0.1:10000         127.0.0.1:56163         ESTABLISHED -               
tcp      529      0 127.0.0.1:10000         127.0.0.1:56157         CLOSE_WAIT  -               
tcp      529      0 127.0.0.1:10000         127.0.0.1:56167         CLOSE_WAIT  -               
tcp      529      0 127.0.0.1:10000         127.0.0.1:56159         CLOSE_WAIT  -  

Wait while fcgi processes remaining connections (in CLOSE_WAIT state) until it hits that one 
in ESTABLISHED state and hangs forever. 

strace output :

accept(3, {sa_family=AF_INET, sin_port=htons(56165), sin_addr=inet_addr("127.0.0.1")}, [16]) = 11
read(11, "\1\1\0\1\0\10\0\0\0\1\0\0\0\0\0\0\1\4\0\1\1\346\2\0\f\0QUERY_S"..., 8192) = 528
time(NULL)                              = 1253037688
select(0, [], [], [], {30, 0})          = 0 (Timeout)
write(11, "\1\6\0\1\0q\7\0Content-Type: text/plain\r"..., 152) = 152
write(11, "\1\7\0\1\0\0\0\0\1\6\0\1\0\0\0\0\1\3\0\1\0\10\0\0\0\0\0\0\0\0\0\0"..., 32) = -1 EPIPE (Broken pipe)
--- SIGPIPE (Broken pipe) @ 0 (0) ---
time(NULL)                              = 1253037718
write(11, "\1\7\0\1\0\0\0\0\1\6\0\1\0\0\0\0\1\3\0\1\0\10\0\0\0\0\0\0\0\0\0\0\1"..., 1168) = -1 EPIPE (Broken pipe)
--- SIGPIPE (Broken pipe) @ 0 (0) ---
write(11, "\1\7\0\1\0\0\0\0\1\6\0\1\0\0\0\0\1\3\0\1\0\10\0\0\0\0\0\0\0\0\0\0\1"..., 1200) = -1 EPIPE (Broken pipe)
--- SIGPIPE (Broken pipe) @ 0 (0) ---
shutdown(11, 2 /* send and receive */)  = -1 ENOTCONN (Transport endpoint is not connected)
accept(3, {sa_family=AF_INET, sin_port=htons(56167), sin_addr=inet_addr("127.0.0.1")}, [16]) = 12
read(12, "\1\1\0\1\0\10\0\0\0\1\0\0\0\0\0\0\1\4\0\1\1\346\2\0\f\0QUERY_S"..., 8192) = 528
time(NULL)                              = 1253037718
select(0, [], [], [], {30, 0})          = 0 (Timeout)
write(12, "\1\6\0\1\0q\7\0Content-Type: text/plain\r"..., 152) = 152
write(12, "\1\7\0\1\0\0\0\0\1\6\0\1\0\0\0\0\1\3\0\1\0\10\0\0\0\0\0\0\0\0\0\0"..., 32) = -1 EPIPE (Broken pipe)
--- SIGPIPE (Broken pipe) @ 0 (0) ---
time(NULL)                              = 1253037748
write(12, "\1\7\0\1\0\0\0\0\1\6\0\1\0\0\0\0\1\3\0\1\0\10\0\0\0\0\0\0\0\0\0\0\1"..., 1168) = -1 EPIPE (Broken pipe)
--- SIGPIPE (Broken pipe) @ 0 (0) ---
write(12, "\1\7\0\1\0\0\0\0\1\6\0\1\0\0\0\0\1\3\0\1\0\10\0\0\0\0\0\0\0\0\0\0\1"..., 1200) = -1 EPIPE (Broken pipe)
--- SIGPIPE (Broken pipe) @ 0 (0) ---
shutdown(12, 2 /* send and receive */)  = -1 ENOTCONN (Transport endpoint is not connected)
accept(3, {sa_family=AF_INET, sin_port=htons(56163), sin_addr=inet_addr("127.0.0.1")}, [16]) = 13
read(13, 

And this 'read' never terminates. There is a tcpdump of such session at http://ygrek.org.ua/files/fcgi.dump (connection
 in question is at port 55424 cause it was another run -- tcpdump -X -r fcgi.dump 'tcp port 55424'  | less) - but there 
is nothing outstanding as for me.).

The strange thing is that the connection is in ESTABLISHED state even before fcgi 'accept'ed it, and even then it can't read
anything from it, nor receive an error. I tried to set SO_RCVTIMEO on fcgi channel, but then it hang in subsequent 'select'.
Anyway, I feel like this situation is very strange and of "can't happen" kind. I would greatly appreciate any pointers cause I am
out of ideas.

ocamlnet is 2.2.9-6+b1 from debian testing
$ cat /proc/version 
Linux version 2.6.26-2-686 (Debian 2.6.26-17lenny2) ([email protected]) (gcc version 4.1.3 20080704 (prerelease) (Debian 4.1.2-25)) #1 SMP Fri Aug 14 01:27:18 UTC 2009
$ sudo nginx -v
nginx version: nginx/0.6.32

(It was also observed on another almost identical debian installation and on
Linux oldub 2.6.28-15-generic #49-Ubuntu SMP Tue Aug 18 18:40:08 UTC 2009 i686 GNU/Linux)

-- 
ygrek <[email protected]>

------------------------------------------------------------------------------
Come build with us! The BlackBerry&reg; Developer Conference in SF, CA
is the only developer event you need to attend this year. Jumpstart your
developing skills, take BlackBerry mobile applications to market and stay 
ahead of the curve. Join us from November 9&#45;12, 2009. Register now&#33;
http://p.sf.net/sfu/devconf