Forum: NGINX can get "uwsgi_buffering off" working..

Posted by kirpit (Guest)
on 2012-12-06 20:32
(Received via mailing list)
Hi,

I'm just trying to setup a non-blocking server backed with uwsgi/gevent. 
So
I need to turn off uwsgi buffering as it's necessary. However, it seems
quite impossible to get it working even though it says "46382#0: *1 http
upstream process non buffered downstream" within the debug output and I
started to consider that would be a bug. I've tried both with v1.2.5 and
v1.2.4.

Here the output belongs to requesting a static file that is handled by
uwsgi itself (via "static-map" directive;
http://projects.unbit.it/uwsgi/wiki/Doc).

And here is the minimal setup and outputs:

nginx -V
################################
configure arguments: --prefix=/opt/local
--with-cc-opt='-I/opt/local/include -O2' --with-ld-opt=-L/opt/local/lib
--conf-path=/opt/local/etc/nginx/nginx.conf
--error-log-path=/opt/local/var/log/nginx/error.log
--http-log-path=/opt/local/var/log/nginx/access.log
--pid-path=/opt/local/var/run/nginx/nginx.pid
--lock-path=/opt/local/var/run/nginx/nginx.lock
--http-client-body-temp-path=/opt/local/var/run/nginx/client_body_temp
--http-proxy-temp-path=/opt/local/var/run/nginx/proxy_temp
--http-fastcgi-temp-path=/opt/local/var/run/nginx/fastcgi_temp
--http-uwsgi-temp-path=/opt/local/var/run/nginx/uwsgi_temp --with-ipv6
--with-http_gzip_static_module --with-http_ssl_module --with-debug

nginx.conf
################################
# path prefixes
daemon on;
master_process on;
pid /data/log/nginx/nginx.pid;
error_log /data/log/nginx/main-errors.log error;

events {
    debug_connection        127.0.0.1;
}

http {
    include         mime.types;
    include         uwsgi_params;
    include         uwsgicluster;
    access_log      /data/log/nginx/main-access.log;

    # gevent async server!
    uwsgi_buffering                 off;

# www (application) server
server {
    server_name     $host;
    listen          80 default_server deferred;
    access_log      /data/log/nginx/$host-access.log;
    uwsgi_buffering off; # gevent async server!

    location ~ ^/(favicon\.ico|robots\.txt)$ {
        root            /data/app/pycore/static_extra;
        log_not_found   off;
        access_log      off;
    }

    location / {
        uwsgi_pass  uwsgicluster;
    }
}

}
################################


uwsgi daemon.log
################################
Thu Dec  6 21:10:50 2012 - spawned uWSGI worker 2 (pid: 46388, cores: 
100)
Thu Dec  6 21:10:50 2012 - mapping worker 1 to CPUs:
Thu Dec  6 21:10:50 2012 - spawned uWSGI worker 3 (pid: 46389, cores: 
100)
Thu Dec  6 21:10:50 2012 - mapping worker 2 to CPUs:
Thu Dec  6 21:10:50 2012 - spawned uWSGI worker 4 (pid: 46390, cores: 
100)
Thu Dec  6 21:10:50 2012 - *** running gevent loop engine
[addr:0x10c9db0d0] ***
Thu Dec  6 21:10:50 2012 - *** Stats server enabled on 
/tmp/uwsgistat.sock
fd: 15 ***
Thu Dec  6 21:10:50 2012 - mapping worker 3 to CPUs:
Thu Dec  6 21:10:50 2012 - mapping worker 4 to CPUs:
Thu Dec  6 21:10:50 2012 - [uwsgi-daemons] spawning "memcached -m 512"
tripall.com {address space usage: 2522730496 bytes/2405MB} {rss usage:
6287360 bytes/5MB} [pid: 46387|app: 0|req: -1/1] 127.0.0.1 () {48 vars 
in
1395 bytes} [Thu Dec  6 21:11:30 2012] GET /static/css/bootstrap.min.css 
=>
generated 4096 bytes in 40 msecs via sendfile() (HTTP/1.1 200) 2 headers 
in
89 bytes (2 switches on core 99)
Thu Dec  6 21:11:30 2012 - ...The work of process 46387 is done. Seeya!
Thu Dec  6 21:11:30 2012 - Gracefully killing worker 1 (pid: 46387)...
Thu Dec  6 21:11:30 2012 - stopping gevent signals watchers for worker 1
(pid: 46387)...
Thu Dec  6 21:11:30 2012 - stopping gevent sockets watchers for worker 1
(pid: 46387)...
Thu Dec  6 21:11:30 2012 - main gevent watchers stopped for worker 1 
(pid:
46387)...
Thu Dec  6 21:11:30 2012 - Respawned uWSGI worker 1 (new pid: 46397)
Thu Dec  6 21:11:30 2012 - mapping worker 1 to CPUs:
Thu Dec  6 21:11:30 2012 - *** running gevent loop engine
[addr:0x10c9db0d0] ***
Thu Dec  6 21:12:31 2012 - *** HARAKIRI ON WORKER 2 (pid: 46388, try: 1) 
***
Thu Dec  6 21:12:31 2012 - *** backtrace of 46388 ***
Thu Dec  6 21:12:31 2012 - 0   uwsgi
0x000000010c9bb1db uwsgi_backtrace + 43
Thu Dec  6 21:12:31 2012 - 1   uwsgi
0x000000010c9baf11 what_i_am_doing + 49
Thu Dec  6 21:12:31 2012 - 2   libsystem_c.dylib
0x00007fff896698ea _sigtramp + 26
Thu Dec  6 21:12:31 2012 - 3   ???
0x00007f8ee3c13990 0x0 + 140251683174800
Thu Dec  6 21:12:31 2012 - 4   core.so
0x000000010e49c08b ev_run + 1124
Thu Dec  6 21:12:31 2012 - 5   core.so
0x000000010e4bab6b __pyx_pw_6gevent_4core_4loop_15run + 615
Thu Dec  6 21:12:31 2012 - 6   Python
 0x000000010d073747 PyEval_EvalFrameEx + 9911
Thu Dec  6 21:12:31 2012 - 7   Python
 0x000000010d071046 PyEval_EvalCodeEx + 1990
Thu Dec  6 21:12:31 2012 - 8   Python
 0x000000010d006a1b function_call + 347
Thu Dec  6 21:12:31 2012 - 9   Python
 0x000000010cfe3421 PyObject_Call + 97
Thu Dec  6 21:12:31 2012 - 10  Python
 0x000000010cfeef46 instancemethod_call + 502
Thu Dec  6 21:12:31 2012 - 11  Python
 0x000000010cfe3421 PyObject_Call + 97
Thu Dec  6 21:12:31 2012 - 12  Python
 0x000000010d077de8 PyEval_CallObjectWithKeywords + 168
Thu Dec  6 21:12:31 2012 - 13  greenlet.so
0x000000010e4946f9 g_initialstub + 865
Thu Dec  6 21:12:31 2012 - 14  greenlet.so
0x000000010e493eff g_switch + 293
Thu Dec  6 21:12:31 2012 - 15  greenlet.so
0x000000010e494ebf green_switch + 20
Thu Dec  6 21:12:31 2012 - 16  Python
 0x000000010cfe3421 PyObject_Call + 97
Thu Dec  6 21:12:31 2012 - 17  Python
 0x000000010d077de8 PyEval_CallObjectWithKeywords + 168
Thu Dec  6 21:12:31 2012 - 18  Python
 0x000000010cff7e0e methoddescr_call + 318
Thu Dec  6 21:12:31 2012 - 19  Python
 0x000000010cfe3421 PyObject_Call + 97
Thu Dec  6 21:12:31 2012 - 20  Python
 0x000000010d073a0a PyEval_EvalFrameEx + 10618
Thu Dec  6 21:12:31 2012 - 21  Python
 0x000000010d071046 PyEval_EvalCodeEx + 1990
Thu Dec  6 21:12:31 2012 - 22  Python
 0x000000010d07863d fast_function + 285
Thu Dec  6 21:12:31 2012 - 23  Python
 0x000000010d0737e8 PyEval_EvalFrameEx + 10072
Thu Dec  6 21:12:31 2012 - 24  Python
 0x000000010d071046 PyEval_EvalCodeEx + 1990
Thu Dec  6 21:12:31 2012 - 25  Python
 0x000000010d07863d fast_function + 285
Thu Dec  6 21:12:31 2012 - 26  Python
 0x000000010d0737e8 PyEval_EvalFrameEx + 10072
Thu Dec  6 21:12:31 2012 - 27  Python
 0x000000010d071046 PyEval_EvalCodeEx + 1990
Thu Dec  6 21:12:31 2012 - 28  Python
 0x000000010d006a1b function_call + 347
Thu Dec  6 21:12:31 2012 - 29  Python
 0x000000010cfe3421 PyObject_Call + 97
Thu Dec  6 21:12:31 2012 - 30  Python
 0x000000010cfeef46 instancemethod_call + 502
Thu Dec  6 21:12:31 2012 - 31  Python
 0x000000010cfe3421 PyObject_Call + 97
Thu Dec  6 21:12:31 2012 - 32  Python
 0x000000010cfe35ff call_function_tail + 95
Thu Dec  6 21:12:31 2012 - 33  Python
 0x000000010cfe386e PyObject_CallMethod + 318
Thu Dec  6 21:12:31 2012 - 34  uwsgi
0x000000010c9db5e8 gevent_loop + 1304
Thu Dec  6 21:12:31 2012 - 35  uwsgi
0x000000010c9bf71d uwsgi_ignition + 317
Thu Dec  6 21:12:31 2012 - 36  uwsgi
0x000000010c9bf318 uwsgi_start + 6344
Thu Dec  6 21:12:31 2012 - 37  uwsgi
0x000000010c9bd273 main + 6995
Thu Dec  6 21:12:31 2012 - 38  libdyld.dylib
0x00007fff8db7d7e1 start + 0
Thu Dec  6 21:12:31 2012 - 39  ???
0x0000000000000003 0x0 + 3
Thu Dec  6 21:12:31 2012 - *** end of backtrace ***
Thu Dec  6 21:12:33 2012 - *** HARAKIRI ON WORKER 2 (pid: 46388, try: 2) 
***
Thu Dec  6 21:12:34 2012 - DAMN ! worker 2 (pid: 46388) died, killed by
signal 9 :( trying respawn ...
Thu Dec  6 21:12:34 2012 - Respawned uWSGI worker 2 (new pid: 46401)
Thu Dec  6 21:12:34 2012 - mapping worker 2 to CPUs:
################################


nginx debug output:
################################
2012/12/06 21:11:30 [debug] 46382#0: *1 accept: 127.0.0.1 fd:3
2012/12/06 21:11:30 [debug] 46382#0: *1 event timer add: 3:
60000:1354821150093
2012/12/06 21:11:30 [debug] 46382#0: *1 kevent set event: 3: ft:-1 
fl:0025
2012/12/06 21:11:30 [debug] 46382#0: *2 accept: 127.0.0.1 fd:9
2012/12/06 21:11:30 [debug] 46382#0: *2 event timer add: 9:
60000:1354821150093
2012/12/06 21:11:30 [debug] 46382#0: *2 kevent set event: 9: ft:-1 
fl:0025
2012/12/06 21:11:30 [debug] 46382#0: *1 kevent: 3: ft:-1 fl:0025
ff:00000000 d:1084 ud:00007F8742055AE0
2012/12/06 21:11:30 [debug] 46382#0: *1 malloc: 00007F8742023A00:1256
2012/12/06 21:11:30 [debug] 46382#0: *1 posix_memalign:
00007F8741C1E0C0:256 @16
2012/12/06 21:11:30 [debug] 46382#0: *1 malloc: 00007F8742007C00:1024
2012/12/06 21:11:30 [debug] 46382#0: *1 posix_memalign:
00007F8742008000:4096 @16
2012/12/06 21:11:30 [debug] 46382#0: *1 http process request line
2012/12/06 21:11:30 [debug] 46382#0: *1 recv: eof:0, avail:1084, err:0
2012/12/06 21:11:30 [debug] 46382#0: *1 recv: fd:3 1024 of 1024
2012/12/06 21:11:30 [debug] 46382#0: *1 http request line: "GET
/static/css/bootstrap.min.css HTTP/1.1"
2012/12/06 21:11:30 [debug] 46382#0: *1 http uri:
"/static/css/bootstrap.min.css"
2012/12/06 21:11:30 [debug] 46382#0: *1 http args: ""
2012/12/06 21:11:30 [debug] 46382#0: *1 http exten: "css"
2012/12/06 21:11:30 [debug] 46382#0: *1 http process request header line
2012/12/06 21:11:30 [debug] 46382#0: *1 http header: "Host: tripall.com"
2012/12/06 21:11:30 [debug] 46382#0: *1 http header: "Connection:
keep-alive"
2012/12/06 21:11:30 [debug] 46382#0: *1 http header: "Cache-Control:
max-age=0"
2012/12/06 21:11:30 [debug] 46382#0: *1 http header: "Authorization: 
Basic
ZXJ0dXI6YmFoYXJpeWU="
2012/12/06 21:11:30 [debug] 46382#0: *1 http header: "User-Agent:
Mozilla/5.0 (Macintosh; Intel Mac OS X 10_8_2) AppleWebKit/537.4 (KHTML,
like Gecko) Chrome/22.0.1229.79 Safari/537.4"
2012/12/06 21:11:30 [debug] 46382#0: *1 http header: "Accept:
text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8"
2012/12/06 21:11:30 [debug] 46382#0: *1 http header: "Accept-Encoding:
gzip,deflate,sdch"
2012/12/06 21:11:30 [debug] 46382#0: *1 http header: "Accept-Language:
en-US,en;q=0.8"
2012/12/06 21:11:30 [debug] 46382#0: *1 http header: "Accept-Charset:
ISO-8859-1,utf-8;q=0.7,*;q=0.3"
2012/12/06 21:11:30 [debug] 46382#0: *1 http header: "Cookie:
_nm_expiry_ng=47c5f6ac-3b44-428f-ae73-d1bb48d9fd6b;
JSESSIONID=B7D8C155FE2B0235F75CD4EB751DD2DB;
__utma=1.1759916378.1347958332.1347958332.1347958332.1; __utmc=1;
__utmz=1.1347958332.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none);
csrftoken=TNY9lk0guaPmierieEmSeVm3cNozzzs4; djdt=hide;
sessionid=405335e2ec3cc7f574c29a6d4a3790be;
csrftoken=TNY9lk0guaPmierieEmSeVm3cNozzzs4;
__utma=2927093.410235394.1351698122.1354799223.1354803506.25;
__utmc=2927093;
__utmz=2927093.1351698122.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none)"
2012/12/06 21:11:30 [debug] 46382#0: *1 http alloc large header buffer
2012/12/06 21:11:30 [debug] 46382#0: *1 malloc: 00007F8742009000:8192
2012/12/06 21:11:30 [debug] 46382#0: *1 http large header alloc:
00007F8742009000 8192
2012/12/06 21:11:30 [debug] 46382#0: *1 http large header copy: 7
2012/12/06 21:11:30 [debug] 46382#0: *1 recv: eof:0, avail:60, err:0
2012/12/06 21:11:30 [debug] 46382#0: *1 recv: fd:3 60 of 8185
2012/12/06 21:11:30 [debug] 46382#0: *1 http header: "Range:
bytes=4096-4096"
2012/12/06 21:11:30 [debug] 46382#0: *1 http header: "If-Range: Wed, 28 
Nov
2012 11:25:02 GMT"
2012/12/06 21:11:30 [debug] 46382#0: *1 http header done
2012/12/06 21:11:30 [debug] 46382#0: *1 event timer del: 3: 
1354821150093
2012/12/06 21:11:30 [debug] 46382#0: *1 rewrite phase: 0
2012/12/06 21:11:30 [debug] 46382#0: *1 test location: "/"
2012/12/06 21:11:30 [debug] 46382#0: *1 test location: ~
"^/(favicon\.ico|robots\.txt)$"
2012/12/06 21:11:30 [debug] 46382#0: *1 using configuration "/"
2012/12/06 21:11:30 [debug] 46382#0: *1 http cl:-1 max:1048576
2012/12/06 21:11:30 [debug] 46382#0: *1 rewrite phase: 2
2012/12/06 21:11:30 [debug] 46382#0: *1 post rewrite phase: 3
2012/12/06 21:11:30 [debug] 46382#0: *1 generic phase: 4
2012/12/06 21:11:30 [debug] 46382#0: *1 generic phase: 5
2012/12/06 21:11:30 [debug] 46382#0: *1 access phase: 6
2012/12/06 21:11:30 [debug] 46382#0: *1 access phase: 7
2012/12/06 21:11:30 [debug] 46382#0: *1 post access phase: 8
2012/12/06 21:11:30 [debug] 46382#0: *1 http init upstream, client 
timer: 0
2012/12/06 21:11:30 [debug] 46382#0: *1 kevent set event: 3: ft:-2 
fl:0025
2012/12/06 21:11:30 [debug] 46382#0: *1 posix_memalign:
00007F8741C1E1C0:256 @16
2012/12/06 21:11:30 [debug] 46382#0: *1 posix_memalign:
00007F8742017E00:4096 @16
2012/12/06 21:11:30 [debug] 46382#0: *1 http script copy: "QUERY_STRING"
2012/12/06 21:11:30 [debug] 46382#0: *1 uwsgi param: "QUERY_STRING: "
2012/12/06 21:11:30 [debug] 46382#0: *1 http script copy: 
"REQUEST_METHOD"
2012/12/06 21:11:30 [debug] 46382#0: *1 http script var: "GET"
2012/12/06 21:11:30 [debug] 46382#0: *1 uwsgi param: "REQUEST_METHOD: 
GET"
2012/12/06 21:11:30 [debug] 46382#0: *1 http script copy: "CONTENT_TYPE"
2012/12/06 21:11:30 [debug] 46382#0: *1 uwsgi param: "CONTENT_TYPE: "
2012/12/06 21:11:30 [debug] 46382#0: *1 http script copy: 
"CONTENT_LENGTH"
2012/12/06 21:11:30 [debug] 46382#0: *1 uwsgi param: "CONTENT_LENGTH: "
2012/12/06 21:11:30 [debug] 46382#0: *1 http script copy: "REQUEST_URI"
2012/12/06 21:11:30 [debug] 46382#0: *1 http script var:
"/static/css/bootstrap.min.css"
2012/12/06 21:11:30 [debug] 46382#0: *1 uwsgi param: "REQUEST_URI:
/static/css/bootstrap.min.css"
2012/12/06 21:11:30 [debug] 46382#0: *1 http script copy: "PATH_INFO"
2012/12/06 21:11:30 [debug] 46382#0: *1 http script var:
"/static/css/bootstrap.min.css"
2012/12/06 21:11:30 [debug] 46382#0: *1 uwsgi param: "PATH_INFO:
/static/css/bootstrap.min.css"
2012/12/06 21:11:30 [debug] 46382#0: *1 http script copy: 
"DOCUMENT_ROOT"
2012/12/06 21:11:30 [debug] 46382#0: *1 http script var: 
"/opt/local/html"
2012/12/06 21:11:30 [debug] 46382#0: *1 uwsgi param: "DOCUMENT_ROOT:
/opt/local/html"
2012/12/06 21:11:30 [debug] 46382#0: *1 http script copy: 
"SERVER_PROTOCOL"
2012/12/06 21:11:30 [debug] 46382#0: *1 http script var: "HTTP/1.1"
2012/12/06 21:11:30 [debug] 46382#0: *1 uwsgi param: "SERVER_PROTOCOL:
HTTP/1.1"
2012/12/06 21:11:30 [debug] 46382#0: *1 http script copy: "REMOTE_ADDR"
2012/12/06 21:11:30 [debug] 46382#0: *1 http script var: "127.0.0.1"
2012/12/06 21:11:30 [debug] 46382#0: *1 uwsgi param: "REMOTE_ADDR:
127.0.0.1"
2012/12/06 21:11:30 [debug] 46382#0: *1 http script copy: "REMOTE_PORT"
2012/12/06 21:11:30 [debug] 46382#0: *1 http script var: "53675"
2012/12/06 21:11:30 [debug] 46382#0: *1 uwsgi param: "REMOTE_PORT: 
53675"
2012/12/06 21:11:30 [debug] 46382#0: *1 http script copy: "SERVER_PORT"
2012/12/06 21:11:30 [debug] 46382#0: *1 http script var: "80"
2012/12/06 21:11:30 [debug] 46382#0: *1 uwsgi param: "SERVER_PORT: 80"
2012/12/06 21:11:30 [debug] 46382#0: *1 http script copy: "SERVER_NAME"
2012/12/06 21:11:30 [debug] 46382#0: *1 http script var: "$host"
2012/12/06 21:11:30 [debug] 46382#0: *1 uwsgi param: "SERVER_NAME: 
$host"
2012/12/06 21:11:30 [debug] 46382#0: *1 uwsgi param: "HTTP_HOST: 
tripall.com
"
2012/12/06 21:11:30 [debug] 46382#0: *1 uwsgi param: "HTTP_CONNECTION:
keep-alive"
2012/12/06 21:11:30 [debug] 46382#0: *1 uwsgi param: 
"HTTP_CACHE_CONTROL:
max-age=0"
2012/12/06 21:11:30 [debug] 46382#0: *1 uwsgi param: 
"HTTP_AUTHORIZATION:
Basic ZXJ0dXI6YmFoYXJpeWU="
2012/12/06 21:11:30 [debug] 46382#0: *1 uwsgi param: "HTTP_USER_AGENT:
Mozilla/5.0 (Macintosh; Intel Mac OS X 10_8_2) AppleWebKit/537.4 (KHTML,
like Gecko) Chrome/22.0.1229.79 Safari/537.4"
2012/12/06 21:11:30 [debug] 46382#0: *1 uwsgi param: "HTTP_ACCEPT:
text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8"
2012/12/06 21:11:30 [debug] 46382#0: *1 uwsgi param: 
"HTTP_ACCEPT_ENCODING:
gzip,deflate,sdch"
2012/12/06 21:11:30 [debug] 46382#0: *1 uwsgi param: 
"HTTP_ACCEPT_LANGUAGE:
en-US,en;q=0.8"
2012/12/06 21:11:30 [debug] 46382#0: *1 uwsgi param: 
"HTTP_ACCEPT_CHARSET:
ISO-8859-1,utf-8;q=0.7,*;q=0.3"
2012/12/06 21:11:30 [debug] 46382#0: *1 uwsgi param: "HTTP_COOKIE:
_nm_expiry_ng=47c5f6ac-3b44-428f-ae73-d1bb48d9fd6b;
JSESSIONID=B7D8C155FE2B0235F75CD4EB751DD2DB;
__utma=1.1759916378.1347958332.1347958332.1347958332.1; __utmc=1;
__utmz=1.1347958332.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none);
csrftoken=TNY9lk0guaPmierieEmSeVm3cNozzzs4; djdt=hide;
sessionid=405335e2ec3cc7f574c29a6d4a3790be;
csrftoken=TNY9lk0guaPmierieEmSeVm3cNozzzs4;
__utma=2927093.410235394.1351698122.1354799223.1354803506.25;
__utmc=2927093;
__utmz=2927093.1351698122.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none)"
2012/12/06 21:11:30 [debug] 46382#0: *1 uwsgi param: "HTTP_RANGE:
bytes=4096-4096"
2012/12/06 21:11:30 [debug] 46382#0: *1 uwsgi param: "HTTP_IF_RANGE: 
Wed,
28 Nov 2012 11:25:02 GMT"
2012/12/06 21:11:30 [debug] 46382#0: *1 http cleanup add: 
00007F87420183F8
2012/12/06 21:11:30 [debug] 46382#0: *1 get ip hash peer, try: 1
2012/12/06 21:11:30 [debug] 46382#0: *1 get rr peer, try: 1
2012/12/06 21:11:30 [debug] 46382#0: *1 socket 10
2012/12/06 21:11:30 [debug] 46382#0: *1 connect to 127.0.0.1:9001, fd:10 
#3
2012/12/06 21:11:30 [debug] 46382#0: *1 kevent set event: 10: ft:-1 
fl:0025
2012/12/06 21:11:30 [debug] 46382#0: *1 kevent set event: 10: ft:-2 
fl:0025
2012/12/06 21:11:30 [debug] 46382#0: *1 http upstream connect: -2
2012/12/06 21:11:30 [debug] 46382#0: *1 posix_memalign:
00007F8741C1E810:128 @16
2012/12/06 21:11:30 [debug] 46382#0: *1 event timer add: 10:
60000:1354821150094
2012/12/06 21:11:30 [debug] 46382#0: *1 http finalize request: -4,
"/static/css/bootstrap.min.css?" a:1, c:2
2012/12/06 21:11:30 [debug] 46382#0: *1 http request count:2 blk:0
2012/12/06 21:11:30 [debug] 46382#0: *1 kevent: 3: ft:-2 fl:0025
ff:00000000 d:146988 ud:00007F8742063AE0
2012/12/06 21:11:30 [debug] 46382#0: *1 http run request:
"/static/css/bootstrap.min.css?"
2012/12/06 21:11:30 [debug] 46382#0: *1 http upstream check client, 
write
event:1, "/static/css/bootstrap.min.css"
2012/12/06 21:11:30 [debug] 46382#0: *1 kevent: 10: ft:-2 fl:0025
ff:00000000 d:146988 ud:00007F8742063BC0
2012/12/06 21:11:30 [debug] 46382#0: *1 http upstream request:
"/static/css/bootstrap.min.css?"
2012/12/06 21:11:30 [debug] 46382#0: *1 http upstream send request 
handler
2012/12/06 21:11:30 [debug] 46382#0: *1 http upstream send request
2012/12/06 21:11:30 [debug] 46382#0: *1 chain writer buf fl:0 s:1399
2012/12/06 21:11:30 [debug] 46382#0: *1 chain writer in: 
00007F8742018458
2012/12/06 21:11:30 [debug] 46382#0: *1 writev: 1399 of 1399
2012/12/06 21:11:30 [debug] 46382#0: *1 chain writer out: 
0000000000000000
2012/12/06 21:11:30 [debug] 46382#0: *1 event timer del: 10: 
1354821150094
2012/12/06 21:11:30 [debug] 46382#0: *1 event timer add: 10:
60000:1354821150095
2012/12/06 21:11:30 [debug] 46382#0: *1 kevent: 10: ft:-2 fl:0025
ff:00000000 d:146988 ud:00007F8742063BC0
2012/12/06 21:11:30 [debug] 46382#0: *1 http upstream request:
"/static/css/bootstrap.min.css?"
2012/12/06 21:11:30 [debug] 46382#0: *1 http upstream dummy handler
2012/12/06 21:11:30 [debug] 46382#0: *1 kevent: 10: ft:-1 fl:0025
ff:00000000 d:89 ud:00007F8742055BC0
2012/12/06 21:11:30 [debug] 46382#0: *1 http upstream request:
"/static/css/bootstrap.min.css?"
2012/12/06 21:11:30 [debug] 46382#0: *1 http upstream process header
2012/12/06 21:11:30 [debug] 46382#0: *1 malloc: 00007F8742018E00:4096
2012/12/06 21:11:30 [debug] 46382#0: *1 recv: eof:0, avail:89, err:0
2012/12/06 21:11:30 [debug] 46382#0: *1 recv: fd:10 4096 of 4096
2012/12/06 21:11:30 [debug] 46382#0: *1 http uwsgi status 200 "200 OK"
2012/12/06 21:11:30 [debug] 46382#0: *1 http uwsgi header: 
"Content-Length:
113975"
2012/12/06 21:11:30 [debug] 46382#0: *1 http uwsgi header: 
"Last-Modified:
Wed, 28 Nov 2012 11:25:02 GMT"
2012/12/06 21:11:30 [debug] 46382#0: *1 http uwsgi header done
2012/12/06 21:11:30 [debug] 46382#0: *1 HTTP/1.1 200 OK
Server: nginx/1.2.4
Date: Thu, 06 Dec 2012 19:11:30 GMT
Content-Length: 113975
Connection: keep-alive
Last-Modified: Wed, 28 Nov 2012 11:25:02 GMT

2012/12/06 21:11:30 [debug] 46382#0: *1 write new buf t:1 f:0
00007F87420186B0, pos 00007F87420186B0, size: 171 file: 0, size: 0
2012/12/06 21:11:30 [debug] 46382#0: *1 http write filter: l:0 f:0 s:171
2012/12/06 21:11:30 [debug] 46382#0: *1 tcp_nodelay
2012/12/06 21:11:30 [debug] 46382#0: *1 http upstream process non 
buffered
downstream
2012/12/06 21:11:30 [debug] 46382#0: *1 http output filter
"/static/css/bootstrap.min.css?"
2012/12/06 21:11:30 [debug] 46382#0: *1 http copy filter:
"/static/css/bootstrap.min.css?"
2012/12/06 21:11:30 [debug] 46382#0: *1 http postpone filter
"/static/css/bootstrap.min.css?" 00007F8742018780
2012/12/06 21:11:30 [debug] 46382#0: *1 write old buf t:1 f:0
00007F87420186B0, pos 00007F87420186B0, size: 171 file: 0, size: 0
2012/12/06 21:11:30 [debug] 46382#0: *1 write new buf t:0 f:0
0000000000000000, pos 00007F8742018E59, size: 4007 file: 0, size: 0
2012/12/06 21:11:30 [debug] 46382#0: *1 http write filter: l:0 f:1 
s:4178
2012/12/06 21:11:30 [debug] 46382#0: *1 http write filter limit 0
2012/12/06 21:11:30 [debug] 46382#0: *1 writev: 4178 of 4178
2012/12/06 21:11:30 [debug] 46382#0: *1 http write filter 
0000000000000000
2012/12/06 21:11:30 [debug] 46382#0: *1 http copy filter: 0
"/static/css/bootstrap.min.css?"
2012/12/06 21:11:30 [debug] 46382#0: *1 event timer: 10, old:
1354821150095, new: 1354821150136
2012/12/06 21:11:30 [debug] 46382#0: *1 kevent: 10: ft:-1 fl:8025
ff:00000000 d:89 ud:00007F8742055BC0
2012/12/06 21:11:30 [debug] 46382#0: *1 http upstream request:
"/static/css/bootstrap.min.css?"
2012/12/06 21:11:30 [debug] 46382#0: *1 http upstream process non 
buffered
upstream
2012/12/06 21:11:30 [debug] 46382#0: *1 recv: eof:1, avail:89, err:0
2012/12/06 21:11:30 [debug] 46382#0: *1 recv: fd:10 89 of 4096
2012/12/06 21:11:30 [debug] 46382#0: *1 http output filter
"/static/css/bootstrap.min.css?"
2012/12/06 21:11:30 [debug] 46382#0: *1 http copy filter:
"/static/css/bootstrap.min.css?"
2012/12/06 21:11:30 [debug] 46382#0: *1 http postpone filter
"/static/css/bootstrap.min.css?" 00007F8742018780
2012/12/06 21:11:30 [debug] 46382#0: *1 write new buf t:0 f:0
0000000000000000, pos 00007F8742018E00, size: 89 file: 0, size: 0
2012/12/06 21:11:30 [debug] 46382#0: *1 http write filter: l:0 f:1 s:89
2012/12/06 21:11:30 [debug] 46382#0: *1 http write filter limit 0
2012/12/06 21:11:30 [debug] 46382#0: *1 writev: 89 of 89
2012/12/06 21:11:30 [debug] 46382#0: *1 http write filter 
0000000000000000
2012/12/06 21:11:30 [debug] 46382#0: *1 http copy filter: 0
"/static/css/bootstrap.min.css?"
2012/12/06 21:11:30 [debug] 46382#0: *1 recv: eof:1, avail:0, err:0
2012/12/06 21:11:30 [debug] 46382#0: *1 finalize http upstream request: 
0
2012/12/06 21:11:30 [debug] 46382#0: *1 finalize http uwsgi request
2012/12/06 21:11:30 [debug] 46382#0: *1 free rr peer 1 0
2012/12/06 21:11:30 [debug] 46382#0: *1 close http upstream connection: 
10
2012/12/06 21:11:30 [debug] 46382#0: *1 free: 00007F8741C1E810, unused: 
48
2012/12/06 21:11:30 [debug] 46382#0: *1 event timer del: 10: 
1354821150095
2012/12/06 21:11:30 [debug] 46382#0: *1 reusable connection: 0
2012/12/06 21:11:30 [debug] 46382#0: *1 http output filter
"/static/css/bootstrap.min.css?"
2012/12/06 21:11:30 [debug] 46382#0: *1 http copy filter:
"/static/css/bootstrap.min.css?"
2012/12/06 21:11:30 [debug] 46382#0: *1 http postpone filter
"/static/css/bootstrap.min.css?" 00007FFF51F15500
2012/12/06 21:11:30 [debug] 46382#0: *1 write new buf t:0 f:0
0000000000000000, pos 0000000000000000, size: 0 file: 0, size: 0
2012/12/06 21:11:30 [debug] 46382#0: *1 http write filter: l:1 f:0 s:0
2012/12/06 21:11:30 [debug] 46382#0: *1 http copy filter: 0
"/static/css/bootstrap.min.css?"
2012/12/06 21:11:30 [debug] 46382#0: *1 http finalize request: 0,
"/static/css/bootstrap.min.css?" a:1, c:1
2012/12/06 21:11:30 [debug] 46382#0: *1 set http keepalive handler
2012/12/06 21:11:30 [debug] 46382#0: *1 http close request
2012/12/06 21:11:30 [debug] 46382#0: *1 http log handler
2012/12/06 21:11:30 [error] 46382#0: *1 testing "/opt/local/html" 
existence
failed (2: No such file or directory) while logging request, client:
127.0.0.1, server: $host, request: "GET /static/css/bootstrap.min.css
HTTP/1.1", upstream: "uwsgi://127.0.0.1:9001", host: "tripall.com"
2012/12/06 21:11:30 [debug] 46382#0: *1 free: 00007F8742018E00
2012/12/06 21:11:30 [debug] 46382#0: *1 free: 00007F8742008000, unused: 
0
2012/12/06 21:11:30 [debug] 46382#0: *1 free: 00007F8742017E00, unused: 
1049
2012/12/06 21:11:30 [debug] 46382#0: *1 event timer add: 3:
75000:1354821165139
2012/12/06 21:11:30 [debug] 46382#0: *1 free: 00007F8742023A00
2012/12/06 21:11:30 [debug] 46382#0: *1 free: 00007F8742007C00
2012/12/06 21:11:30 [debug] 46382#0: *1 hc free: 0000000000000000 0
2012/12/06 21:11:30 [debug] 46382#0: *1 hc busy: 00007F8741C1E140 1
2012/12/06 21:11:30 [debug] 46382#0: *1 free: 00007F8742009000
2012/12/06 21:11:30 [debug] 46382#0: *1 reusable connection: 1
2012/12/06 21:11:30 [debug] 46382#0: *1 kevent: 3: ft:-2 fl:0025
ff:00000000 d:146988 ud:00007F8742063AE0
2012/12/06 21:11:30 [debug] 46382#0: *1 http empty handler
2012/12/06 21:11:30 [debug] 46382#0: *1 kevent: 3: ft:-2 fl:0025
ff:00000000 d:146988 ud:00007F8742063AE0
2012/12/06 21:11:30 [debug] 46382#0: *1 http empty handler
2012/12/06 21:11:40 [debug] 46382#0: *2 kevent: 9: ft:-1 fl:8025
ff:00000000 d:0 ud:00007F8742055B50
2012/12/06 21:11:40 [debug] 46382#0: *2 malloc: 00007F8742023A00:1256
2012/12/06 21:11:40 [debug] 46382#0: *2 posix_memalign:
00007F8741C1EAF0:256 @16
2012/12/06 21:11:40 [debug] 46382#0: *2 malloc: 00007F8742024000:1024
2012/12/06 21:11:40 [debug] 46382#0: *2 posix_memalign:
00007F8742007C00:4096 @16
2012/12/06 21:11:40 [debug] 46382#0: *2 http process request line
2012/12/06 21:11:40 [debug] 46382#0: *2 recv: eof:1, avail:0, err:0
2012/12/06 21:11:40 [info] 46382#0: *2 client prematurely closed 
connection
while reading client request line, client: 127.0.0.1, server: $host
2012/12/06 21:11:40 [debug] 46382#0: *2 http finalize request: 400, "?"
a:1, c:1
2012/12/06 21:11:40 [debug] 46382#0: *2 http terminate request count:1
2012/12/06 21:11:40 [debug] 46382#0: *2 http terminate cleanup count:1 
blk:0
2012/12/06 21:11:40 [debug] 46382#0: *2 http request count:1 blk:0
2012/12/06 21:11:40 [debug] 46382#0: *2 http close request
2012/12/06 21:11:40 [debug] 46382#0: *2 http log handler
2012/12/06 21:11:40 [error] 46382#0: *2 testing "/opt/local/html" 
existence
failed (2: No such file or directory) while logging request, client:
127.0.0.1, server: $host
2012/12/06 21:11:40 [debug] 46382#0: *2 free: 00007F8742007C00, unused: 
2319
2012/12/06 21:11:40 [debug] 46382#0: *2 close http connection: 9
2012/12/06 21:11:40 [debug] 46382#0: *2 event timer del: 9: 
1354821150093
2012/12/06 21:11:40 [debug] 46382#0: *2 reusable connection: 0
2012/12/06 21:11:40 [debug] 46382#0: *2 free: 00007F8742024000
2012/12/06 21:11:40 [debug] 46382#0: *2 free: 00007F8742023A00
2012/12/06 21:11:40 [debug] 46382#0: *2 free: 00007F8741C1E710, unused: 
8
2012/12/06 21:11:40 [debug] 46382#0: *2 free: 00007F8741C1EAF0, unused: 
128
2012/12/06 21:12:45 [debug] 46382#0: *1 event timer del: 3: 
1354821165139
2012/12/06 21:12:45 [debug] 46382#0: *1 http keepalive handler
2012/12/06 21:12:45 [debug] 46382#0: *1 close http connection: 3
2012/12/06 21:12:45 [debug] 46382#0: *1 reusable connection: 0
2012/12/06 21:12:45 [debug] 46382#0: *1 free: 0000000000000000
2012/12/06 21:12:45 [debug] 46382#0: *1 free: 0000000000000000
2012/12/06 21:12:45 [debug] 46382#0: *1 free: 0000000000000000
2012/12/06 21:12:45 [debug] 46382#0: *1 free: 00007F8741C1DEC0, unused: 
8
2012/12/06 21:12:45 [debug] 46382#0: *1 free: 00007F8741C1E0C0, unused: 
0
2012/12/06 21:12:45 [debug] 46382#0: *1 free: 00007F8741C1E1C0, unused: 
208
2012/12/06 21:12:45 [debug] 46382#0: *4 accept: 127.0.0.1 fd:3
2012/12/06 21:12:45 [debug] 46382#0: *4 event timer add: 3:
60000:1354821225146
2012/12/06 21:12:45 [debug] 46382#0: *4 kevent set event: 3: ft:-1 
fl:0025
2012/12/06 21:12:45 [debug] 46382#0: *4 kevent: 3: ft:-1 fl:0025
ff:00000000 d:916 ud:00007F8742055AE1
2012/12/06 21:12:45 [debug] 46382#0: *4 malloc: 00007F8742023A00:1256
2012/12/06 21:12:45 [debug] 46382#0: *4 posix_memalign:
00007F8741C1DEC0:256 @16
2012/12/06 21:12:45 [debug] 46382#0: *4 malloc: 00007F8742024000:1024
2012/12/06 21:12:45 [debug] 46382#0: *4 posix_memalign:
00007F8742007C00:4096 @16
2012/12/06 21:12:45 [debug] 46382#0: *4 http process request line
2012/12/06 21:12:45 [debug] 46382#0: *4 recv: eof:0, avail:916, err:0
2012/12/06 21:12:45 [debug] 46382#0: *4 recv: fd:3 916 of 1024
2012/12/06 21:12:45 [debug] 46382#0: *4 http request line: "GET
/favicon.ico HTTP/1.1"
2012/12/06 21:12:45 [debug] 46382#0: *4 http uri: "/favicon.ico"
2012/12/06 21:12:45 [debug] 46382#0: *4 http args: ""
2012/12/06 21:12:45 [debug] 46382#0: *4 http exten: "ico"
2012/12/06 21:12:45 [debug] 46382#0: *4 http process request header line
2012/12/06 21:12:45 [debug] 46382#0: *4 http header: "Host: tripall.com"
2012/12/06 21:12:45 [debug] 46382#0: *4 http header: "Connection:
keep-alive"
2012/12/06 21:12:45 [debug] 46382#0: *4 http header: "Authorization: 
Basic
ZXJ0dXI6YmFoYXJpeWU="
2012/12/06 21:12:45 [debug] 46382#0: *4 http header: "Accept: */*"
2012/12/06 21:12:45 [debug] 46382#0: *4 http header: "User-Agent:
Mozilla/5.0 (Macintosh; Intel Mac OS X 10_8_2) AppleWebKit/537.4 (KHTML,
like Gecko) Chrome/22.0.1229.79 Safari/537.4"
2012/12/06 21:12:45 [debug] 46382#0: *4 http header: "Accept-Encoding:
gzip,deflate,sdch"
2012/12/06 21:12:45 [debug] 46382#0: *4 http header: "Accept-Language:
en-US,en;q=0.8"
2012/12/06 21:12:45 [debug] 46382#0: *4 http header: "Accept-Charset:
ISO-8859-1,utf-8;q=0.7,*;q=0.3"
2012/12/06 21:12:45 [debug] 46382#0: *4 http header: "Cookie:
_nm_expiry_ng=47c5f6ac-3b44-428f-ae73-d1bb48d9fd6b;
JSESSIONID=B7D8C155FE2B0235F75CD4EB751DD2DB;
__utma=1.1759916378.1347958332.1347958332.1347958332.1; __utmc=1;
__utmz=1.1347958332.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none);
csrftoken=TNY9lk0guaPmierieEmSeVm3cNozzzs4; djdt=hide;
sessionid=405335e2ec3cc7f574c29a6d4a3790be;
csrftoken=TNY9lk0guaPmierieEmSeVm3cNozzzs4;
__utma=2927093.410235394.1351698122.1354799223.1354803506.25;
__utmc=2927093;
__utmz=2927093.1351698122.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none)"
2012/12/06 21:12:45 [debug] 46382#0: *4 http header done
2012/12/06 21:12:45 [debug] 46382#0: *4 event timer del: 3: 
1354821225146
2012/12/06 21:12:45 [debug] 46382#0: *4 rewrite phase: 0
2012/12/06 21:12:45 [debug] 46382#0: *4 test location: "/"
2012/12/06 21:12:45 [debug] 46382#0: *4 test location: ~
"^/(favicon\.ico|robots\.txt)$"
2012/12/06 21:12:45 [debug] 46382#0: *4 using configuration
"^/(favicon\.ico|robots\.txt)$"
2012/12/06 21:12:45 [debug] 46382#0: *4 http cl:-1 max:1048576
2012/12/06 21:12:45 [debug] 46382#0: *4 rewrite phase: 2
2012/12/06 21:12:45 [debug] 46382#0: *4 post rewrite phase: 3
2012/12/06 21:12:45 [debug] 46382#0: *4 generic phase: 4
2012/12/06 21:12:45 [debug] 46382#0: *4 generic phase: 5
2012/12/06 21:12:45 [debug] 46382#0: *4 access phase: 6
2012/12/06 21:12:45 [debug] 46382#0: *4 access phase: 7
2012/12/06 21:12:45 [debug] 46382#0: *4 post access phase: 8
2012/12/06 21:12:45 [debug] 46382#0: *4 content phase: 9
2012/12/06 21:12:45 [debug] 46382#0: *4 content phase: 10
2012/12/06 21:12:45 [debug] 46382#0: *4 content phase: 11
2012/12/06 21:12:45 [debug] 46382#0: *4 content phase: 12
2012/12/06 21:12:45 [debug] 46382#0: *4 http filename:
"/data/app/pycore/static_extra/favicon.ico"
2012/12/06 21:12:45 [debug] 46382#0: *4 add cleanup: 00007F87420086F8
2012/12/06 21:12:45 [debug] 46382#0: *4 http finalize request: 404,
"/favicon.ico?" a:1, c:1
2012/12/06 21:12:45 [debug] 46382#0: *4 http special response: 404,
"/favicon.ico?"
2012/12/06 21:12:45 [debug] 46382#0: *4 http set discard body
2012/12/06 21:12:45 [debug] 46382#0: *4 HTTP/1.1 404 Not Found
Server: nginx/1.2.4
Date: Thu, 06 Dec 2012 19:12:45 GMT
Content-Type: text/html
Content-Length: 570
Connection: keep-alive

2012/12/06 21:12:45 [debug] 46382#0: *4 write new buf t:1 f:0
00007F8742008778, pos 00007F8742008778, size: 154 file: 0, size: 0
2012/12/06 21:12:45 [debug] 46382#0: *4 http write filter: l:0 f:0 s:154
2012/12/06 21:12:45 [debug] 46382#0: *4 http output filter 
"/favicon.ico?"
2012/12/06 21:12:45 [debug] 46382#0: *4 http copy filter: 
"/favicon.ico?"
2012/12/06 21:12:45 [debug] 46382#0: *4 http postpone filter
"/favicon.ico?" 00007F8742008990
2012/12/06 21:12:45 [debug] 46382#0: *4 write old buf t:1 f:0
00007F8742008778, pos 00007F8742008778, size: 154 file: 0, size: 0
2012/12/06 21:12:45 [debug] 46382#0: *4 write new buf t:0 f:0
0000000000000000, pos 000000010DD77940, size: 116 file: 0, size: 0
2012/12/06 21:12:45 [debug] 46382#0: *4 write new buf t:0 f:0
0000000000000000, pos 000000010DD77300, size: 52 file: 0, size: 0
2012/12/06 21:12:45 [debug] 46382#0: *4 write new buf t:0 f:0
0000000000000000, pos 000000010DD77370, size: 402 file: 0, size: 0
2012/12/06 21:12:45 [debug] 46382#0: *4 http write filter: l:1 f:0 s:724
2012/12/06 21:12:45 [debug] 46382#0: *4 http write filter limit 0
2012/12/06 21:12:45 [debug] 46382#0: *4 writev: 724 of 724
2012/12/06 21:12:45 [debug] 46382#0: *4 http write filter 
0000000000000000
2012/12/06 21:12:45 [debug] 46382#0: *4 http copy filter: 0 
"/favicon.ico?"
2012/12/06 21:12:45 [debug] 46382#0: *4 http finalize request: 0,
"/favicon.ico?" a:1, c:1
2012/12/06 21:12:45 [debug] 46382#0: *4 set http keepalive handler
2012/12/06 21:12:45 [debug] 46382#0: *4 http close request
2012/12/06 21:12:45 [debug] 46382#0: *4 http log handler
2012/12/06 21:12:45 [debug] 46382#0: *4 free: 00007F8742007C00, unused: 
528
2012/12/06 21:12:45 [debug] 46382#0: *4 event timer add: 3:
75000:1354821240146
2012/12/06 21:12:45 [debug] 46382#0: *4 free: 00007F8742023A00
2012/12/06 21:12:45 [debug] 46382#0: *4 free: 00007F8742024000
2012/12/06 21:12:45 [debug] 46382#0: *4 hc free: 0000000000000000 0
2012/12/06 21:12:45 [debug] 46382#0: *4 hc busy: 0000000000000000 0
2012/12/06 21:12:45 [debug] 46382#0: *4 tcp_nodelay
2012/12/06 21:12:45 [debug] 46382#0: *4 reusable connection: 1
2012/12/06 21:14:00 [debug] 46382#0: *4 event timer del: 3: 
1354821240146
2012/12/06 21:14:00 [debug] 46382#0: *4 http keepalive handler
2012/12/06 21:14:00 [debug] 46382#0: *4 close http connection: 3
2012/12/06 21:14:00 [debug] 46382#0: *4 reusable connection: 0
2012/12/06 21:14:00 [debug] 46382#0: *4 free: 0000000000000000
2012/12/06 21:14:00 [debug] 46382#0: *4 free: 0000000000000000
2012/12/06 21:14:00 [debug] 46382#0: *4 free: 00007F8741C1E710, unused: 
8
2012/12/06 21:14:00 [debug] 46382#0: *4 free: 00007F8741C1DEC0, unused: 
128
################################
Posted by Maxim Dounin (Guest)
on 2012-12-07 17:06
(Received via mailing list)
Hello!

On Thu, Dec 06, 2012 at 09:31:45PM +0200, kirpit wrote:

> uwsgi itself (via "static-map" directive;
> http://projects.unbit.it/uwsgi/wiki/Doc).

It looks like you are trying to solve wrong problem.  From nginx
point of view response was fully got from upstream (as upstream
closed the connection), and everything in nginx itself works fine.
But per uwsgi logs you've provided it looks like something bad
happened in uwsgi worker process, but it's doesn't look like
something related to nginx:

[...]

> Thu Dec  6 21:12:31 2012 - *** HARAKIRI ON WORKER 2 (pid: 46388, try: 1) ***
> Thu Dec  6 21:12:31 2012 - *** backtrace of 46388 ***
> Thu Dec  6 21:12:31 2012 - 0   uwsgi 0x000000010c9bb1db uwsgi_backtrace + 43
> Thu Dec  6 21:12:31 2012 - 1   uwsgi 0x000000010c9baf11 what_i_am_doing + 49
> Thu Dec  6 21:12:31 2012 - 2   libsystem_c.dylib 0x00007fff896698ea _sigtramp + 
26
> Thu Dec  6 21:12:31 2012 - 3   ??? 0x00007f8ee3c13990 0x0 + 140251683174800
> Thu Dec  6 21:12:31 2012 - 4   core.so 0x000000010e49c08b ev_run + 1124

[...]

> Thu Dec  6 21:12:31 2012 - *** end of backtrace ***
> Thu Dec  6 21:12:33 2012 - *** HARAKIRI ON WORKER 2 (pid: 46388, try: 2) ***
> Thu Dec  6 21:12:34 2012 - DAMN ! worker 2 (pid: 46388) died, killed by
> signal 9 :( trying respawn ...
> Thu Dec  6 21:12:34 2012 - Respawned uWSGI worker 2 (new pid: 46401)
> Thu Dec  6 21:12:34 2012 - mapping worker 2 to CPUs:

[...]

Here how it goes from nginx point of view:

> 2012/12/06 21:11:30 [debug] 46382#0: *1 socket 10
> 2012/12/06 21:11:30 [debug] 46382#0: *1 connect to 127.0.0.1:9001, fd:10 #3

(connected to the backend)

[...]

> 2012/12/06 21:11:30 [debug] 46382#0: *1 recv: fd:10 4096 of 4096
> 2012/12/06 21:11:30 [debug] 46382#0: *1 http uwsgi status 200 "200 OK"
> 2012/12/06 21:11:30 [debug] 46382#0: *1 http uwsgi header: "Content-Length: 
113975"
> 2012/12/06 21:11:30 [debug] 46382#0: *1 http uwsgi header: "Last-Modified: Wed, 
28 Nov 2012 11:25:02 GMT"
> 2012/12/06 21:11:30 [debug] 46382#0: *1 http uwsgi header done
> 2012/12/06 21:11:30 [debug] 46382#0: *1 HTTP/1.1 200 OK

(got response headers and start of the response body)

[...]

> 2012/12/06 21:11:30 [debug] 46382#0: *1 http upstream process non buffered 
upstream
> 2012/12/06 21:11:30 [debug] 46382#0: *1 recv: eof:1, avail:89, err:0
> 2012/12/06 21:11:30 [debug] 46382#0: *1 recv: fd:10 89 of 4096

(got some mory bytes of the response body)

> 2012/12/06 21:11:30 [debug] 46382#0: *1 recv: eof:1, avail:0, err:0

(got EOF from the backend)


--
Maxim Dounin
http://nginx.com/support.html
Please log in before posting. Registration is free and takes only a minute.
Existing account (Switch to SSL-encrypted connection)
NEW: Do you have a Google/GoogleMail or Yahoo account? No registration required!
Log in with Google account | Log in with Yahoo account
No account? Register here.