| From | Sent On | Attachments |
|---|---|---|
| Dave Hayes | Jun 16, 2011 3:25 pm | |
| Maxim Dounin | Jun 17, 2011 12:53 am | |
| Igor Sysoev | Jun 17, 2011 2:21 am | |
| Dave Hayes | Jun 17, 2011 11:40 am |
| Subject: | Sendfile EAGAIN and FastCGI | |
|---|---|---|
| From: | Dave Hayes (da...@jetcafe.org) | |
| Date: | Jun 16, 2011 3:25:53 pm | |
| List: | ru.sysoev.nginx | |
Hello. I'm using FreeBSD 7.4-RELEASE with Nginx 1.0.3 built from ports:
# nginx -V nginx: nginx version: nginx/1.0.3 nginx: TLS SNI support enabled nginx: configure arguments: --prefix=/usr/local/etc/nginx --with-cc-opt='-I /usr/local/include' --with-ld-opt='-L /usr/local/lib' --conf-path=/usr/local/etc/nginx/nginx.conf --sbin-path=/usr/local/sbin/nginx --pid-path=/var/run/nginx.pid --error-log-path=/var/log/nginx-error.log --user=www --group=www --with-debug --with-file-aio --http-client-body-temp-path=/var/tmp/nginx/client_body_temp --http-fastcgi-temp-path=/var/tmp/nginx/fastcgi_temp --http-proxy-temp-path=/var/tmp/nginx/proxy_temp --http-scgi-temp-path=/var/tmp/nginx/scgi_temp --http-uwsgi-temp-path=/var/tmp/nginx/uwsgi_temp --http-log-path=/var/log/nginx-access.log --with-http_gzip_static_module --with-http_realip_module --with-http_ssl_module --with-http_stub_status_module --with-http_sub_module --with-pcre
I'm also using FCGI to run a web application:
# pkg_info | grep FCGI p5-FCGI-ProcManager-0.19 Functions for managing FastCGI applications p5-FCGI-Spawn-0.16.1 FastCGI server for CGI-like applications multiprocessing
It appears when I make a request larger than some value, the debug output claims that sendfile() is returning EAGAIN, at which point the request times out. Is this my misconfiguration, an nginx bug, an OS bug, or something else I've not yet figured out? Debug output follows:
2011/06/16 12:54:07 [debug] 51363#0: *1 http cl:21413 max:115343360 2011/06/16 12:54:07 [debug] 51363#0: *1 rewrite phase: 3 2011/06/16 12:54:07 [debug] 51363#0: *1 post rewrite phase: 4 2011/06/16 12:54:07 [debug] 51363#0: *1 generic phase: 5 2011/06/16 12:54:07 [debug] 51363#0: *1 generic phase: 6 2011/06/16 12:54:07 [debug] 51363#0: *1 generic phase: 7 2011/06/16 12:54:07 [debug] 51363#0: *1 access phase: 8 2011/06/16 12:54:07 [debug] 51363#0: *1 access phase: 9 2011/06/16 12:54:07 [debug] 51363#0: *1 post access phase: 10 2011/06/16 12:54:07 [debug] 51363#0: *1 try files phase: 11 2011/06/16 12:54:07 [debug] 51363#0: *1 posix_memalign: 0000000801268000:4096 @16 2011/06/16 12:54:07 [debug] 51363#0: *1 http client request body preread 8118 2011/06/16 12:54:07 [debug] 51363#0: *1 malloc: 0000000801269000:8192 2011/06/16 12:54:07 [debug] 51363#0: *1 http read client request body 2011/06/16 12:54:07 [debug] 51363#0: *1 SSL_read: 7177 2011/06/16 12:54:07 [debug] 51363#0: *1 SSL_read: 1015 2011/06/16 12:54:07 [debug] 51363#0: *1 http client request body recv 8192 2011/06/16 12:54:07 [debug] 51363#0: *1 add cleanup: 0000000801268248 2011/06/16 12:54:07 [debug] 51363#0: *1 hashed path: /var/tmp/nginx/client_body_temp/0000000001 2011/06/16 12:54:07 [debug] 51363#0: *1 temp fd:34 2011/06/16 12:54:07 [warn] 51363#0: *1 a client request body is buffered to a temporary file /var/tmp/nginx/client_body_temp/0000000001, client: 205.147.26.121, server: wiki.dream-tech.com, request: "POST /bin/save/Some/File HTTP/1.1", host: "wiki.dream-tech.com", referrer: "https://mywiki.dream-tech.com/bin/edit/Some/File?t=1308252237;nowysiwyg=1" 2011/06/16 12:54:07 [debug] 51363#0: *1 write: 34, 0000000801269000, 8192, 0 2011/06/16 12:54:07 [debug] 51363#0: *1 SSL_read: 5103 2011/06/16 12:54:07 [debug] 51363#0: *1 http client request body recv 5103 2011/06/16 12:54:07 [debug] 51363#0: *1 http client request body rest 0 2011/06/16 12:54:07 [debug] 51363#0: *1 write: 34, 0000000801269000, 5103, 8192 2011/06/16 12:54:07 [debug] 51363#0: *1 http init upstream, client timer: 0 2011/06/16 12:54:07 [debug] 51363#0: *1 kevent set event: 33: ft:-2 fl:0025 2011/06/16 12:54:07 [debug] 51363#0: *1 http script copy: "LOCATION_MATCH" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script copy: "bin" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "LOCATION_MATCH: bin" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script copy: "SCRIPT_FILENAME" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script copy: "/www/foswiki" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script var: "/bin/save" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "SCRIPT_FILENAME: /www/foswiki/bin/save" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script copy: "PATH_INFO" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script var: "/Some/File" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "PATH_INFO: /Some/File" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script copy: "SCRIPT_NAME" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script var: "/bin/save" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "SCRIPT_NAME: /bin/save" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script copy: "QUERY_STRING" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "QUERY_STRING: " 2011/06/16 12:54:07 [debug] 51363#0: *1 http script copy: "REQUEST_METHOD" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script var: "POST" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "REQUEST_METHOD: POST" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script copy: "CONTENT_TYPE" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script var: "application/x-www-form-urlencoded" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "CONTENT_TYPE: application/x-www-form-urlencoded" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script copy: "CONTENT_LENGTH" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script var: "21413" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "CONTENT_LENGTH: 21413" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script copy: "SCRIPT_NAME" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script var: "/bin/save" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "SCRIPT_NAME: /bin/save" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script copy: "REQUEST_URI" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script var: "/bin/save/Some/File" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "REQUEST_URI: /bin/save/Some/File" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script copy: "DOCUMENT_URI" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script var: "/bin/save/Some/File" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "DOCUMENT_URI: /bin/save/Some/File" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script copy: "DOCUMENT_ROOT" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script var: "/www/mywikis/mywiki.dream-tech.com" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "DOCUMENT_ROOT: /www/mywikis/mywiki.dream-tech.com" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script copy: "SERVER_PROTOCOL" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script var: "HTTP/1.1" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "SERVER_PROTOCOL: HTTP/1.1" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script copy: "GATEWAY_INTERFACE" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script copy: "CGI/1.1" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "GATEWAY_INTERFACE: CGI/1.1" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script copy: "SERVER_SOFTWARE" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script copy: "nginx/" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script var: "1.0.3" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "SERVER_SOFTWARE: nginx/1.0.3" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script copy: "REMOTE_ADDR" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script var: "205.147.26.121" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "REMOTE_ADDR: 205.147.26.121" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script copy: "REMOTE_PORT" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script var: "52063" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "REMOTE_PORT: 52063" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script copy: "SERVER_ADDR" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script var: "205.147.26.122" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "SERVER_ADDR: 205.147.26.122" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script copy: "SERVER_PORT" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script var: "443" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "SERVER_PORT: 443" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script copy: "SERVER_NAME" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script var: "wiki.dream-tech.com" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "SERVER_NAME: wiki.dream-tech.com" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script copy: "REDIRECT_STATUS" 2011/06/16 12:54:07 [debug] 51363#0: *1 http script copy: "200" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "REDIRECT_STATUS: 200" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "HTTP_HOST: wiki.dream-tech.com" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "HTTP_USER_AGENT: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.5; rv:2.0.1) Gecko/20100101 Firefox/4.0.1" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "HTTP_ACCEPT: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "HTTP_ACCEPT_LANGUAGE: en-us,en;q=0.5" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "HTTP_ACCEPT_ENCODING: gzip, deflate" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "HTTP_ACCEPT_CHARSET: ISO-8859-1,utf-8;q=0.7,*;q=0.7" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "HTTP_KEEP_ALIVE: 115" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "HTTP_DNT: 1" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "HTTP_CONNECTION: keep-alive" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "HTTP_REFERER: https://mywiki.dream-tech.com/bin/edit/Some/File?t=1308252237;nowysiwyg=1" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "HTTP_CONTENT_TYPE: application/x-www-form-urlencoded" 2011/06/16 12:54:07 [debug] 51363#0: *1 fastcgi param: "HTTP_CONTENT_LENGTH: 21413" 2011/06/16 12:54:07 [debug] 51363#0: *1 http cleanup add: 0000000801268BF8 2011/06/16 12:54:07 [debug] 51363#0: *1 get rr peer, try: 1 2011/06/16 12:54:07 [debug] 51363#0: *1 socket 35 2011/06/16 12:54:07 [debug] 51363#0: *1 connect to unix:/var/tmp/sockets/foswiki, fd:35 #2 2011/06/16 12:54:07 [debug] 51363#0: *1 kevent set event: 35: ft:-1 fl:0025 2011/06/16 12:54:07 [debug] 51363#0: *1 connected 2011/06/16 12:54:07 [debug] 51363#0: *1 http upstream connect: 0 2011/06/16 12:54:07 [debug] 51363#0: *1 http upstream send request 2011/06/16 12:54:07 [debug] 51363#0: *1 chain writer buf fl:0 s:1720 2011/06/16 12:54:07 [debug] 51363#0: *1 chain writer buf fl:0 s:8118 2011/06/16 12:54:07 [debug] 51363#0: *1 chain writer buf fl:0 s:10 2011/06/16 12:54:07 [debug] 51363#0: *1 chain writer buf fl:0 s:13295 2011/06/16 12:54:07 [debug] 51363#0: *1 chain writer buf fl:0 s:9 2011/06/16 12:54:07 [debug] 51363#0: *1 chain writer in: 0000000801268C90 2011/06/16 12:54:07 [debug] 51363#0: *1 sendfile() sent only 9848 bytes (35: Resource temporarily unavailable) 2011/06/16 12:54:07 [debug] 51363#0: *1 sendfile: -1, @0 9848:13295 2011/06/16 12:54:07 [debug] 51363#0: *1 chain writer out: 0000000801268CC0 2011/06/16 12:54:07 [debug] 51363#0: *1 event timer add: 35: 60000:1308254107181 2011/06/16 12:54:07 [debug] 51363#0: *1 kevent set event: 35: ft:-2 fl:0025 2011/06/16 12:54:07 [debug] 51363#0: *1 http finalize request: -4, "/bin/save/Some/File?" a:1, c:2 2011/06/16 12:54:07 [debug] 51363#0: *1 http request count:2 blk:0 2011/06/16 12:54:07 [debug] 51363#0: *1 post event 00000008012DE150 2011/06/16 12:54:07 [debug] 51363#0: *1 delete posted event 00000008012DE150 2011/06/16 12:54:07 [debug] 51363#0: *1 http run request: "/bin/save/Some/File?" 2011/06/16 12:54:07 [debug] 51363#0: *1 http upstream check client, write event:1, "/bin/save/Some/File" 2011/06/16 12:55:07 [debug] 51363#0: *1 event timer del: 35: 1308254107181 2011/06/16 12:55:07 [debug] 51363#0: *1 http upstream request: "/bin/save/Some/File?" 2011/06/16 12:55:07 [debug] 51363#0: *1 http upstream send request handler 2011/06/16 12:55:07 [debug] 51363#0: *1 http next upstream, 4 2011/06/16 12:55:07 [debug] 51363#0: *1 free rr peer 1 4 2011/06/16 12:55:07 [error] 51363#0: *1 upstream timed out (60: Operation timed out) while sending request to upstream, client: 205.147.26.121, server: wiki.dream-tech.com, request: "POST /bin/save/Some/File HTTP/1.1", upstream: "fastcgi://unix:/var/tmp/sockets/foswiki:", host: "wiki.dream-tech.com", referrer: "https://mywiki.dream-tech.com/bin/edit/Some/File?t=1308252237;nowysi wyg=1"
Thanks in advance for any insight that can be provided. :)
-- Dave Hayes - Consultant - Altadena CA, USA - da...@jetcafe.org
The opinions expressed above are entirely my own <<<
Do what you can, with what you have, where you are.
_______________________________________________ nginx mailing list ngi...@nginx.org http://nginx.org/mailman/listinfo/nginx





