Re: Повисшие post запросы, backend uwsgi

maxgentry nginx-forum на nginx.us
Вт Дек 28 23:57:45 MSK 2010


> nginx -V
nginx version: nginx/0.8.54
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
--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_stub_status_module
--with-pcre

nginx.conf
[code]
worker_processes  1;
error_log  /var/log/nginx-error.log  debug;
events {
    worker_connections  4096;
}
http {
    include       mime.types;
    default_type  application/octet-stream;
    sendfile        on;
    client_body_in_single_buffer on;
    client_body_buffer_size 16k;
    client_body_timeout 10;
    keepalive_timeout  0;
    upstream test {
        server unix:///var/run/uwsgi.sock;
    }
    server {
        listen       80;
        server_name  localhost;
        location / {
            uwsgi_pass test;
            include uwsgi_params;
        }
        error_page   500 502 503 504  /50x.html;
        location = /50x.html {
            root   /usr/local/www/nginx-dist;
        }
    }
}
[/code]

uwsgi_test.py:
[code]
def application(env, start_response):
    start_response('200 OK', [('Content-Type', 'text/plain')])
    env['wsgi.input'].read()
    yield 'OK\n'
[/code]

[code]
> uwsgi -s /var/run/uwsgi.sock -C -w uwsgi_test -p 1 -d /tmp/log -l 512
*** Starting uWSGI 0.9.6.5 (32bit) on [Tue Dec 28 22:26:27 2010] ***
compiled with version: 4.2.1 20070719  [FreeBSD]
Python version: 2.6.4 (r264:75706, Apr 28 2010, 12:28:32) 
[GCC 4.2.1 20070719  [FreeBSD]]
uWSGI running as root, you can use --uid/--gid/--chroot options
 *** WARNING: you are running uWSGI as root !!! (use the --uid flag) ***

your memory page size is 4096 bytes
allocated 408 bytes (0 KB) for 1 request's buffer.
binding on UNIX socket: /var/run/uwsgi.sock
chmod() socket to 666 for lazy and brave users
your server socket listen backlog is limited to 512 connections
initializing hooks...done.
...getting the applications list from the 'uwsgi_test' module...
uwsgi.applications dictionary is not defined, trying with the
"applications" one...
applications dictionary is not defined, trying with the "application"
callable.
application 0 () ready
setting default application to 0
spawned uWSGI master process (pid: 67897)
spawned uWSGI worker 1 (pid: 67905)
SIGPIPE: writing to a closed pipe/socket/fd (probably the client
disconnected) on request / !!!
write(): Broken pipe [pyutils.c line 101]
[pid: 67905|app: 0|req: 1/1] 10.10.10.10 () {34 vars in 530 bytes} [Tue
Dec 28 22:26:29 2010] POST / => generated 0 bytes in 13107 msecs
(HTTP/1.1 200) 1 headers in 45 bytes (0 async switches on async core 0)
SIGPIPE: writing to a closed pipe/socket/fd (probably the client
disconnected) on request / !!!
write(): Broken pipe [pyutils.c line 101]
[pid: 67905|app: 0|req: 2/2] 10.10.10.11 () {34 vars in 474 bytes} [Tue
Dec 28 22:26:42 2010] POST / => generated 0 bytes in 1880 msecs
(HTTP/1.1 200) 1 headers in 45 bytes (0 async switches on async core 0)
SIGPIPE: writing to a closed pipe/socket/fd (probably the client
disconnected) on request / !!!
write(): Broken pipe [pyutils.c line 101]

[/code]

nginx-error.log:
[code]
2010/12/28 22:26:29 [debug] 67908#0: *1 accept: 10.10.10.10 fd:3
2010/12/28 22:26:29 [debug] 67908#0: *1 event timer add: 3:
60000:782893140
2010/12/28 22:26:29 [debug] 67908#0: *1 kevent set event: 3: ft:-1
fl:0025
2010/12/28 22:26:29 [debug] 67908#0: *1 malloc: 283EF300:656
2010/12/28 22:26:29 [debug] 67908#0: *1 malloc: 28301400:1024
2010/12/28 22:26:29 [debug] 67908#0: *1 posix_memalign: 28322000:4096
@16
2010/12/28 22:26:29 [debug] 67908#0: *1 http process request line
2010/12/28 22:26:29 [debug] 67908#0: *1 recv: eof:0, avail:1452, err:0
2010/12/28 22:26:29 [debug] 67908#0: *1 recv: fd:3 1024 of 1024
2010/12/28 22:26:29 [debug] 67908#0: *1 http request line: "POST /
HTTP/1.1"
2010/12/28 22:26:29 [debug] 67908#0: *1 http uri: "/"
2010/12/28 22:26:29 [debug] 67908#0: *1 http args: ""
2010/12/28 22:26:29 [debug] 67908#0: *1 http exten: ""
2010/12/28 22:26:29 [debug] 67908#0: *1 http process request header
line
2010/12/28 22:26:29 [debug] 67908#0: *1 http header: "Content-Type:
application/x-www-form-urlencoded"
2010/12/28 22:26:29 [debug] 67908#0: *1 http header: "User-Agent:
Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; .NET CLR
2.0.50727)"
2010/12/28 22:26:29 [debug] 67908#0: *1 http header: "Host: 1.1.1.1"
2010/12/28 22:26:29 [debug] 67908#0: *1 http header: "Content-Length:
2475"
2010/12/28 22:26:29 [debug] 67908#0: *1 http header: "Cache-Control:
no-cache"
2010/12/28 22:26:29 [debug] 67908#0: *1 http header done
2010/12/28 22:26:29 [debug] 67908#0: *1 event timer del: 3: 782893140
2010/12/28 22:26:29 [debug] 67908#0: *1 rewrite phase: 0
2010/12/28 22:26:29 [debug] 67908#0: *1 test location: "/nginx_status"
2010/12/28 22:26:29 [debug] 67908#0: *1 test location: "/"
2010/12/28 22:26:29 [debug] 67908#0: *1 using configuration "/"
2010/12/28 22:26:29 [debug] 67908#0: *1 http cl:2475 max:1048576
2010/12/28 22:26:29 [debug] 67908#0: *1 rewrite phase: 2
2010/12/28 22:26:29 [debug] 67908#0: *1 post rewrite phase: 3
2010/12/28 22:26:29 [debug] 67908#0: *1 generic phase: 4
2010/12/28 22:26:29 [debug] 67908#0: *1 generic phase: 5
2010/12/28 22:26:29 [debug] 67908#0: *1 access phase: 6
2010/12/28 22:26:29 [debug] 67908#0: *1 access phase: 7
2010/12/28 22:26:29 [debug] 67908#0: *1 post access phase: 8
2010/12/28 22:26:29 [debug] 67908#0: *1 http client request body preread
796
2010/12/28 22:26:29 [debug] 67908#0: *1 posix_memalign: 28323000:4096
@16
2010/12/28 22:26:29 [debug] 67908#0: *1 http read client request body
2010/12/28 22:26:29 [debug] 67908#0: *1 recv: eof:0, avail:428, err:0
2010/12/28 22:26:29 [debug] 67908#0: *1 recv: fd:3 428 of 1679
2010/12/28 22:26:29 [debug] 67908#0: *1 http client request body recv
428
2010/12/28 22:26:29 [debug] 67908#0: *1 http client request body rest
1251
2010/12/28 22:26:29 [debug] 67908#0: *1 event timer add: 3:
10000:782843157
2010/12/28 22:26:29 [debug] 67908#0: *1 http finalize request: -4, "/?"
a:1, c:2
2010/12/28 22:26:29 [debug] 67908#0: *1 http request count:2 blk:0
2010/12/28 22:26:29 [debug] 67908#0: *1 http run request: "/?"
2010/12/28 22:26:29 [debug] 67908#0: *1 http read client request body
2010/12/28 22:26:29 [debug] 67908#0: *1 recv: eof:0, avail:1251, err:0
2010/12/28 22:26:29 [debug] 67908#0: *1 recv: fd:3 1251 of 1251
2010/12/28 22:26:29 [debug] 67908#0: *1 http client request body recv
1251
2010/12/28 22:26:29 [debug] 67908#0: *1 http client request body rest 0
2010/12/28 22:26:29 [debug] 67908#0: *1 event timer del: 3: 782843157
2010/12/28 22:26:29 [debug] 67908#0: *1 http init upstream, client
timer: 0
2010/12/28 22:26:29 [debug] 67908#0: *1 kevent set event: 3: ft:-2
fl:0025
2010/12/28 22:26:29 [debug] 67908#0: *1 http script copy:
"QUERY_STRING"
2010/12/28 22:26:29 [debug] 67908#0: *1 uwsgi param: "QUERY_STRING: "
2010/12/28 22:26:29 [debug] 67908#0: *1 http script copy:
"REQUEST_METHOD"
2010/12/28 22:26:29 [debug] 67908#0: *1 http script var: "POST"
2010/12/28 22:26:29 [debug] 67908#0: *1 uwsgi param: "REQUEST_METHOD:
POST"
2010/12/28 22:26:29 [debug] 67908#0: *1 http script copy:
"CONTENT_TYPE"
2010/12/28 22:26:29 [debug] 67908#0: *1 http script var:
"application/x-www-form-urlencoded"
2010/12/28 22:26:29 [debug] 67908#0: *1 uwsgi param: "CONTENT_TYPE:
application/x-www-form-urlencoded"
2010/12/28 22:26:29 [debug] 67908#0: *1 http script copy:
"CONTENT_LENGTH"
2010/12/28 22:26:29 [debug] 67908#0: *1 http script var: "2475"
2010/12/28 22:26:29 [debug] 67908#0: *1 uwsgi param: "CONTENT_LENGTH:
2475"
2010/12/28 22:26:29 [debug] 67908#0: *1 http script copy: "REQUEST_URI"
2010/12/28 22:26:29 [debug] 67908#0: *1 http script var: "/"
2010/12/28 22:26:29 [debug] 67908#0: *1 uwsgi param: "REQUEST_URI: /"
2010/12/28 22:26:29 [debug] 67908#0: *1 http script copy: "PATH_INFO"
2010/12/28 22:26:29 [debug] 67908#0: *1 http script var: "/"
2010/12/28 22:26:29 [debug] 67908#0: *1 uwsgi param: "PATH_INFO: /"
2010/12/28 22:26:29 [debug] 67908#0: *1 http script copy:
"DOCUMENT_ROOT"
2010/12/28 22:26:29 [debug] 67908#0: *1 http script var:
"/usr/local/etc/nginx/html"
2010/12/28 22:26:29 [debug] 67908#0: *1 uwsgi param: "DOCUMENT_ROOT:
/usr/local/etc/nginx/html"
2010/12/28 22:26:29 [debug] 67908#0: *1 http script copy:
"SERVER_PROTOCOL"
2010/12/28 22:26:29 [debug] 67908#0: *1 http script var: "HTTP/1.1"
2010/12/28 22:26:29 [debug] 67908#0: *1 uwsgi param: "SERVER_PROTOCOL:
HTTP/1.1"
2010/12/28 22:26:29 [debug] 67908#0: *1 http script copy: "REMOTE_ADDR"
2010/12/28 22:26:29 [debug] 67908#0: *1 http script var: "10.10.10.10"
2010/12/28 22:26:29 [debug] 67908#0: *1 uwsgi param: "REMOTE_ADDR:
10.10.10.10"
2010/12/28 22:26:29 [debug] 67908#0: *1 http script copy: "REMOTE_PORT"
2010/12/28 22:26:29 [debug] 67908#0: *1 http script var: "1391"
2010/12/28 22:26:29 [debug] 67908#0: *1 uwsgi param: "REMOTE_PORT:
1391"
2010/12/28 22:26:29 [debug] 67908#0: *1 http script copy: "SERVER_PORT"
2010/12/28 22:26:29 [debug] 67908#0: *1 http script var: "80"
2010/12/28 22:26:29 [debug] 67908#0: *1 uwsgi param: "SERVER_PORT: 80"
2010/12/28 22:26:29 [debug] 67908#0: *1 http script copy: "SERVER_NAME"
2010/12/28 22:26:29 [debug] 67908#0: *1 http script var: "localhost"
2010/12/28 22:26:29 [debug] 67908#0: *1 uwsgi param: "SERVER_NAME:
localhost"
2010/12/28 22:26:29 [debug] 67908#0: *1 uwsgi param: "HTTP_CONTENT_TYPE:
application/x-www-form-urlencoded"
2010/12/28 22:26:29 [debug] 67908#0: *1 uwsgi param: "HTTP_USER_AGENT:
Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; .NET CLR
2.0.50727)"
2010/12/28 22:26:29 [debug] 67908#0: *1 uwsgi param: "HTTP_HOST:
1.1.1.1"
2010/12/28 22:26:29 [debug] 67908#0: *1 uwsgi param:
"HTTP_CONTENT_LENGTH: 2475"
2010/12/28 22:26:29 [debug] 67908#0: *1 uwsgi param:
"HTTP_CACHE_CONTROL: no-cache"
2010/12/28 22:26:29 [debug] 67908#0: *1 http cleanup add: 28322AEC
2010/12/28 22:26:29 [debug] 67908#0: *1 get rr peer, try: 1
2010/12/28 22:26:29 [debug] 67908#0: *1 socket 12
2010/12/28 22:26:29 [debug] 67908#0: *1 connect to
unix:///var/run/uwsgi.sock, fd:12 #5
2010/12/28 22:26:29 [debug] 67908#0: *1 kevent set event: 12: ft:-1
fl:0025
2010/12/28 22:26:29 [debug] 67908#0: *1 connected
2010/12/28 22:26:29 [debug] 67908#0: *1 http upstream connect: 0
2010/12/28 22:26:29 [debug] 67908#0: *1 http upstream send request
2010/12/28 22:26:29 [debug] 67908#0: *1 chain writer buf fl:0 s:534
2010/12/28 22:26:29 [debug] 67908#0: *1 chain writer buf fl:0 s:2475
2010/12/28 22:26:29 [debug] 67908#0: *1 chain writer in: 28322B18
2010/12/28 22:26:29 [debug] 67908#0: *1 writev: 3009 of 3009
2010/12/28 22:26:29 [debug] 67908#0: *1 chain writer out: 00000000
2010/12/28 22:26:29 [debug] 67908#0: *1 event timer add: 12:
60000:782893172
2010/12/28 22:26:29 [debug] 67908#0: *1 http run request: "/?"
2010/12/28 22:26:29 [debug] 67908#0: *1 http upstream check client,
write event:1, "/"
2010/12/28 22:26:29 [debug] 67908#0: *1 http upstream request: "/?"
2010/12/28 22:26:29 [debug] 67908#0: *1 http upstream process header
2010/12/28 22:26:29 [debug] 67908#0: *1 malloc: 283FB000:4096
2010/12/28 22:26:29 [debug] 67908#0: *1 recv: eof:0, avail:45, err:0
2010/12/28 22:26:29 [debug] 67908#0: *1 recv: fd:12 45 of 4096
2010/12/28 22:26:29 [debug] 67908#0: *1 http uwsgi status 200 "200 OK"
2010/12/28 22:26:29 [debug] 67908#0: *1 http uwsgi header:
"Content-Type: text/plain"
2010/12/28 22:26:29 [debug] 67908#0: *1 http uwsgi header done
2010/12/28 22:26:29 [debug] 67908#0: *1 HTTP/1.1 200 OK
2010/12/28 22:26:29 [debug] 67908#0: *1 write new buf t:1 f:0 28322C50,
pos 28322C50, size: 151 file: 0, size: 0
2010/12/28 22:26:29 [debug] 67908#0: *1 http write filter: l:0 f:0
s:151
2010/12/28 22:26:29 [debug] 67908#0: *1 http cacheable: 0
2010/12/28 22:26:29 [debug] 67908#0: *1 http upstream process upstream
2010/12/28 22:26:29 [debug] 67908#0: *1 pipe read upstream: 0
2010/12/28 22:26:29 [debug] 67908#0: *1 pipe preread: 0
2010/12/28 22:26:29 [debug] 67908#0: *1 pipe buf free s:0 t:1 f:0
283FB000, pos 283FB02D, size: 0 file: 0, size: 0
2010/12/28 22:26:29 [debug] 67908#0: *1 event timer: 12, old: 782893172,
new: 782893172
2010/12/28 22:26:42 [debug] 67908#0: *1 http run request: "/?"
2010/12/28 22:26:42 [debug] 67908#0: *1 http upstream check client,
write event:0, "/"
2010/12/28 22:26:42 [info] 67908#0: *1 kevent() reported that client
closed prematurely connection, so upstream connection is closed too (54:
Connection reset by peer) while reading upstream, client: 10.10.10.10,
server: localhost, request: "POST / HTTP/1.1", upstream:
"uwsgi://unix:///var/run/uwsgi.sock:", host: "1.1.1.1"
2010/12/28 22:26:42 [debug] 67908#0: *1 finalize http upstream request:
499
2010/12/28 22:26:42 [debug] 67908#0: *1 finalize http uwsgi request
2010/12/28 22:26:42 [debug] 67908#0: *1 free rr peer 1 0
2010/12/28 22:26:42 [debug] 67908#0: *1 close http upstream connection:
12
2010/12/28 22:26:42 [debug] 67908#0: *1 event timer del: 12: 782893172
2010/12/28 22:26:42 [debug] 67908#0: *1 http upstream temp fd: -1
2010/12/28 22:26:42 [debug] 67908#0: *1 http output filter "/?"
2010/12/28 22:26:42 [debug] 67908#0: *1 http copy filter: "/?"
2010/12/28 22:26:42 [debug] 67908#0: *1 http postpone filter "/?"
BFBFE7A8
2010/12/28 22:26:42 [debug] 67908#0: *1 http chunk: 0
2010/12/28 22:26:42 [debug] 67908#0: *1 http copy filter: -1 "/?"
2010/12/28 22:26:42 [debug] 67908#0: *1 http finalize request: -1, "/?"
a:1, c:1
2010/12/28 22:26:42 [debug] 67908#0: *1 http terminate request count:1
2010/12/28 22:26:42 [debug] 67908#0: *1 http terminate cleanup count:1
blk:0
2010/12/28 22:26:42 [debug] 67908#0: *1 http posted request: "/?"
2010/12/28 22:26:42 [debug] 67908#0: *1 http terminate handler count:1
2010/12/28 22:26:42 [debug] 67908#0: *1 http request count:1 blk:0
2010/12/28 22:26:42 [debug] 67908#0: *1 http close request
2010/12/28 22:26:42 [debug] 67908#0: *1 http log handler
2010/12/28 22:26:42 [debug] 67908#0: *1 free: 283FB000
2010/12/28 22:26:42 [debug] 67908#0: *1 free: 28322000, unused: 320
2010/12/28 22:26:42 [debug] 67908#0: *1 free: 28323000, unused: 1605
2010/12/28 22:26:42 [debug] 67908#0: *1 close http connection: 3
2010/12/28 22:26:42 [debug] 67908#0: *1 free: 28301400
2010/12/28 22:26:42 [debug] 67908#0: *1 free: 283EF300
2010/12/28 22:26:42 [debug] 67908#0: *1 free: 28317200, unused: 40
[/code]

Posted at Nginx Forum: http://forum.nginx.org/read.php?21,161657,161795#msg-161795




Подробная информация о списке рассылки nginx-ru