nginx 1.0.2 intermittent segfault error 4

inph nginx-forum at nginx.us
Sun May 15 18:42:34 MSD 2011 

Sorry, was in a hurry and didnt even notice.

nginx compiled with -g and -O0 (previously segfaults above were compiled
with -O2)
nginx.conf is the same as before.

Might be worth noting that this segfault took approximately 12 hours to
happen after i recompiled with -g -O0
However this might be down to low traffic between midnight and midday on
Sunday.

# nginx -V
nginx: nginx version: nginx/1.0.2
nginx: TLS SNI support enabled
nginx: configure arguments: --with-debug --prefix=/usr
--sbin-path=/usr/sbin/nginx --conf-path=/etc/nginx/nginx.conf
--pid-path=/var/run/nginx.pid --lock-path=/var/lock/nginx.lock
--user=www --group=www --error-log-path=/var/log/nginx/error.log
--http-log-path=/var/log/nginx/access.log --with-http_ssl_module
--with-http_realip_module --with-http_addition_module
--with-http_sub_module --with-http_dav_module --with-http_flv_module
--with-http_gzip_static_module --with-http_secure_link_module
--with-http_stub_status_module
--http-client-body-temp-path=/var/lib/nginx/body
--http-proxy-temp-path=/var/lib/nginx/proxy
--http-fastcgi-temp-path=/var/lib/nginx/fastcgi
--http-uwsgi-temp-path=/var/lib/nginx/uwsgi
--http-scgi-temp-path=/var/lib/nginx/scgi --without-mail_pop3_module
--without-mail_imap_module --without-mail_smtp_module


# stat core
  File: `core'
  Size: 1359872         Blocks: 2352       IO Block: 4096   regular
file
Device: 807h/2055d      Inode: 18350097    Links: 1
Access: (0600/-rw-------)  Uid: (   48/     www)   Gid: (   48/    
www)
Access: 2011-05-15 12:41:37.000000000 +0000
Modify: 2011-05-15 12:43:32.000000000 +0000
Change: 2011-05-15 12:43:32.000000000 +0000
 Birth: -


# gdb /usr/sbin/nginx /home/www/core
GNU gdb (GDB) 7.2
Copyright (C) 2010 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later
<http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show
copying"
and "show warranty" for details.
This GDB was configured as "i486-slackware-linux".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from /usr/sbin/nginx...done.
[New Thread 9301]

warning: Can't read pathname for load map: Input/output error.
Reading symbols from /lib/libcrypt.so.1...(no debugging symbols
found)...done.
Loaded symbols for /lib/libcrypt.so.1
Reading symbols from /usr/lib/libpcre.so.0...(no debugging symbols
found)...done.
Loaded symbols for /usr/lib/libpcre.so.0
Reading symbols from /usr/lib/libssl.so.0...(no debugging symbols
found)...done.
Loaded symbols for /usr/lib/libssl.so.0
Reading symbols from /usr/lib/libcrypto.so.0...(no debugging symbols
found)...done.
Loaded symbols for /usr/lib/libcrypto.so.0
Reading symbols from /lib/libdl.so.2...(no debugging symbols
found)...done.
Loaded symbols for /lib/libdl.so.2
Reading symbols from /usr/lib/libz.so.1...(no debugging symbols
found)...done.
Loaded symbols for /usr/lib/libz.so.1
Reading symbols from /lib/libc.so.6...(no debugging symbols
found)...done.
Loaded symbols for /lib/libc.so.6
Reading symbols from /lib/ld-linux.so.2...(no debugging symbols
found)...done.
Loaded symbols for /lib/ld-linux.so.2
Reading symbols from /lib/libnss_compat.so.2...(no debugging symbols
found)...done.
Loaded symbols for /lib/libnss_compat.so.2
Reading symbols from /lib/libnsl.so.1...(no debugging symbols
found)...done.
Loaded symbols for /lib/libnsl.so.1
Reading symbols from /lib/libnss_nis.so.2...(no debugging symbols
found)...done.
Loaded symbols for /lib/libnss_nis.so.2
Reading symbols from /lib/libnss_files.so.2...(no debugging symbols
found)...done.
Loaded symbols for /lib/libnss_files.so.2
Core was generated by `nginx:'.
Program terminated with signal 11, Segmentation fault.
#0  0x08085243 in ngx_http_terminate_request (r=0x8985548, rc=400) at
src/http/ngx_http_request.c:2085
2085        ngx_log_debug2(NGX_LOG_DEBUG_HTTP, r->connection->log, 0,
(gdb) backtrace
#0  0x08085243 in ngx_http_terminate_request (r=0x8985548, rc=400) at
src/http/ngx_http_request.c:2085
#1  0x08084c91 in ngx_http_finalize_request (r=0x8985548, rc=400) at
src/http/ngx_http_request.c:1912
#2  0x0808dab7 in ngx_http_read_client_request_body_handler
(r=0x8985548) at src/http/ngx_http_request_body.c:254
#3  0x080849ab in ngx_http_request_handler (ev=0x89ab0ac) at
src/http/ngx_http_request.c:1800
#4  0x08067f7b in ngx_event_process_posted (cycle=0x8946cb8,
posted=0x80eaaf4) at src/event/ngx_event_posted.c:39
#5  0x08066531 in ngx_process_events_and_timers (cycle=0x8946cb8) at
src/event/ngx_event.c:272
#6  0x0807051b in ngx_worker_process_cycle (cycle=0x8946cb8, data=0x0)
at src/os/unix/ngx_process_cycle.c:800
#7  0x0806dc5f in ngx_spawn_process (cycle=0x8946cb8, proc=0x807038a
<ngx_worker_process_cycle>, data=0x0, name=0x80d2e2b "worker process",
respawn=-3)
    at src/os/unix/ngx_process.c:196
#8  0x0806f813 in ngx_start_worker_processes (cycle=0x8946cb8, n=2,
type=-3) at src/os/unix/ngx_process_cycle.c:360
#9  0x0806f05e in ngx_master_process_cycle (cycle=0x8946cb8) at
src/os/unix/ngx_process_cycle.c:136
#10 0x0804c297 in main (argc=1, argv=0xbfdb0fc4) at
src/core/nginx.c:405
(gdb) backtrace full
#0  0x08085243 in ngx_http_terminate_request (r=0x8985548, rc=400) at
src/http/ngx_http_request.c:2085
        cln = 0x0
        mr = 0x8985548
        e = 0x8984dc8
#1  0x08084c91 in ngx_http_finalize_request (r=0x8985548, rc=400) at
src/http/ngx_http_request.c:1912
        c = 0x8992434
        pr = 0x8992434
        clcf = 0x894b804
#2  0x0808dab7 in ngx_http_read_client_request_body_handler
(r=0x8985548) at src/http/ngx_http_request_body.c:254
        rc = 400
#3  0x080849ab in ngx_http_request_handler (ev=0x89ab0ac) at
src/http/ngx_http_request.c:1800
        c = 0x8992434
        r = 0x8985548
        ctx = 0x8984df0
#4  0x08067f7b in ngx_event_process_posted (cycle=0x8946cb8,
posted=0x80eaaf4) at src/event/ngx_event_posted.c:39
        ev = 0x89ab0ac
#5  0x08066531 in ngx_process_events_and_timers (cycle=0x8946cb8) at
src/event/ngx_event.c:272
        flags = 3
        timer = 197
        delta = 0
#6  0x0807051b in ngx_worker_process_cycle (cycle=0x8946cb8, data=0x0)
at src/os/unix/ngx_process_cycle.c:800
        i = 9299
        c = 0xbfdb0cb8
#7  0x0806dc5f in ngx_spawn_process (cycle=0x8946cb8, proc=0x807038a
<ngx_worker_process_cycle>, data=0x0, name=0x80d2e2b "worker process",
respawn=-3)
    at src/os/unix/ngx_process.c:196
        on = 1
        pid = 0
        s = 1
#8  0x0806f813 in ngx_start_worker_processes (cycle=0x8946cb8, n=2,
type=-3) at src/os/unix/ngx_process_cycle.c:360
        i = 1
        ch = {command = 1, pid = 9300, slot = 0, fd = 3}
#9  0x0806f05e in ngx_master_process_cycle (cycle=0x8946cb8) at
src/os/unix/ngx_process_cycle.c:136
        title = 0x898feb6 "master process nginx"
        p = 0x898feca ""
        size = 21
        i = 1
        n = 143944900
        sigio = 0
        set = {__val = {0 <repeats 32 times>}}
        itv = {it_interval = {tv_sec = 135072442, tv_usec = 9299},
it_value = {tv_sec = 0, tv_usec = 0}}
        live = 0
        delay = 0
        ls = 0x0
        ccf = 0x89474b0
#10 0x0804c297 in main (argc=1, argv=0xbfdb0fc4) at
src/core/nginx.c:405
        i = 53
        log = 0x80e88d0
        cycle = 0x8946cb8
        init_cycle = {conf_ctx = 0x0, pool = 0x8945dd0, log = 0x80e88d0,
new_log = {log_level = 0, file = 0x0, connection = 0, handler = 0, data
= 0x0, action = 0x0},
          files = 0x0, free_connections = 0x0, free_connection_n = 0,
reusable_connections_queue = {prev = 0x0, next = 0x0}, listening = {elts
= 0x0, nelts = 0, size = 0,
            nalloc = 0, pool = 0x0}, pathes = {elts = 0x0, nelts = 0,
size = 0, nalloc = 0, pool = 0x0}, open_files = {last = 0x0, part =
{elts = 0x0, nelts = 0, next = 0x0},
            size = 0, nalloc = 0, pool = 0x0}, shared_memory = {last =
0x0, part = {elts = 0x0, nelts = 0, next = 0x0}, size = 0, nalloc = 0,
pool = 0x0}, connection_n = 0,
          files_n = 0, connections = 0x0, read_events = 0x0,
write_events = 0x0, old_cycle = 0x0, conf_file = {len = 21, data =
0x80cf5c2 "/etc/nginx/nginx.conf"},
          conf_param = {len = 0, data = 0x0}, conf_prefix = {len = 11,
data = 0x80cf5c2 "/etc/nginx/nginx.conf"}, prefix = {len = 5, data =
0x80cf5bc "/usr/"}, lock_file = {
            len = 0, data = 0x0}, hostname = {len = 0, data = 0x0}}
        ccf = 0x89474b0
(gdb) quit


[93995.665429] nginx[9301]: segfault at 50545448 ip 08085243 sp bfdb0b50
error 4 in nginx[8048000+97000]

# cat segfault.log |grep "12:43:32"
2011/05/15 12:43:32 [debug] 9812#0: timer delta: 501
2011/05/15 12:43:32 [debug] 9812#0: posted events 00000000
2011/05/15 12:43:32 [debug] 9812#0: worker cycle
2011/05/15 12:43:32 [debug] 9812#0: accept mutex lock failed: 0
2011/05/15 12:43:32 [debug] 9812#0: epoll timer: 500
2011/05/15 12:43:32 [debug] 9301#0: epoll: fd:10 ev:0001 d:08992435
2011/05/15 12:43:32 [debug] 9301#0: *4558 post event 089AB0AC
2011/05/15 12:43:32 [debug] 9301#0: timer delta: 801
2011/05/15 12:43:32 [debug] 9301#0: posted events 089AB0AC
2011/05/15 12:43:32 [debug] 9301#0: posted event 089AB0AC
2011/05/15 12:43:32 [debug] 9301#0: *4558 delete posted event 089AB0AC
2011/05/15 12:43:32 [debug] 9301#0: *4558 malloc: 08985548:680
2011/05/15 12:43:32 [debug] 9301#0: *4558 malloc: 08983960:1024
2011/05/15 12:43:32 [debug] 9301#0: *4558 posix_memalign: 0894AF70:4096
@16
2011/05/15 12:43:32 [debug] 9301#0: *4558 http process request line
2011/05/15 12:43:32 [debug] 9301#0: *4558 recv: fd:10 536 of 1024
2011/05/15 12:43:32 [debug] 9301#0: *4558 http request line: "POST
/index.php?taigachat/list.json HTTP/1.1"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http uri: "/index.php"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http args:
"taigachat/list.json"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http exten: "php"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http process request header
line
2011/05/15 12:43:32 [debug] 9301#0: *4558 http header: "Host:
example.com"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http header: "Connection:
keep-alive"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http header: "Referer:
http://example.com/forum/"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http header: "Content-Length:
142"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http header: "Origin:
http://example.com"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http header:
"X-Requested-With: XMLHttpRequest"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http header: "User-Agent:
Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/534.24 (KHTML, like
Gecko) Chrome/11.0.696.65 Safari/534.24"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http header: "Content-Type:
application/x-www-form-urlencoded"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http header: "Accept:
application/json, text/javascript, */*; q=0.01"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http header: "Accept-Encoding:
gzip,deflate"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http header: "Accept-Language:
da-DK,da;q=0.8,en-US;q=0.6,en;q=0.4"
2011/05/15 12:43:32 [debug] 9301#0: *4558 recv: fd:10 -1 of 488
2011/05/15 12:43:32 [debug] 9301#0: *4558 recv() not ready (11: Resource
temporarily unavailable)
2011/05/15 12:43:32 [debug] 9301#0: posted event 00000000
2011/05/15 12:43:32 [debug] 9301#0: worker cycle
2011/05/15 12:43:32 [debug] 9301#0: accept mutex locked
2011/05/15 12:43:32 [debug] 9301#0: epoll timer: 210
2011/05/15 12:43:32 [debug] 9301#0: epoll: fd:10 ev:0001 d:08992435
2011/05/15 12:43:32 [debug] 9301#0: *4558 post event 089AB0AC
2011/05/15 12:43:32 [debug] 9301#0: timer delta: 12
2011/05/15 12:43:32 [debug] 9301#0: posted events 089AB0AC
2011/05/15 12:43:32 [debug] 9301#0: posted event 089AB0AC
2011/05/15 12:43:32 [debug] 9301#0: *4558 delete posted event 089AB0AC
2011/05/15 12:43:32 [debug] 9301#0: *4558 http process request header
line
2011/05/15 12:43:32 [debug] 9301#0: *4558 recv: fd:10 488 of 488
2011/05/15 12:43:32 [debug] 9301#0: *4558 http header: "Accept-Charset:
ISO-8859-1,utf-8;q=0.7,*;q=0.3"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http header: "Cookie:
__utmz=206500500.1304337103.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none);
xf_user=1931%2C8b0bad949f0d38b81a46469cb9a941ec05485539;
xf_session=094d80a983afbbd15ac06937d4b23798;
__utma=206500500.1451942054.1304337103.1305433729.1305437755.69;
__utmc=206500500; __utmb=206500500.3.10.1305437755"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http header done
2011/05/15 12:43:32 [debug] 9301#0: *4558 event timer del: 10:
4088381035
2011/05/15 12:43:32 [debug] 9301#0: *4558 generic phase: 0
2011/05/15 12:43:32 [debug] 9301#0: *4558 rewrite phase: 1
2011/05/15 12:43:32 [debug] 9301#0: *4558 test location: "/"
2011/05/15 12:43:32 [debug] 9301#0: *4558 test location: "forum/"
2011/05/15 12:43:32 [debug] 9301#0: *4558 test location: ~
"\.(jpg|jpeg|gif|css|png|js|ico)$"
2011/05/15 12:43:32 [debug] 9301#0: *4558 test location: ~ "\.php$"
2011/05/15 12:43:32 [debug] 9301#0: *4558 using configuration "\.php$"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http cl:142 max:52428800
2011/05/15 12:43:32 [debug] 9301#0: *4558 rewrite phase: 3
2011/05/15 12:43:32 [debug] 9301#0: *4558 post rewrite phase: 4
2011/05/15 12:43:32 [debug] 9301#0: *4558 generic phase: 5
2011/05/15 12:43:32 [debug] 9301#0: *4558 generic phase: 6
2011/05/15 12:43:32 [debug] 9301#0: *4558 generic phase: 7
2011/05/15 12:43:32 [debug] 9301#0: *4558 access phase: 8
2011/05/15 12:43:32 [debug] 9301#0: *4558 access phase: 9
2011/05/15 12:43:32 [debug] 9301#0: *4558 post access phase: 10
2011/05/15 12:43:32 [debug] 9301#0: *4558 try files phase: 11
2011/05/15 12:43:32 [debug] 9301#0: *4558 http client request body
preread 137
2011/05/15 12:43:32 [debug] 9301#0: *4558 http read client request body
2011/05/15 12:43:32 [debug] 9301#0: *4558 recv: fd:10 5 of 5
2011/05/15 12:43:32 [debug] 9301#0: *4558 http client request body recv
5
2011/05/15 12:43:32 [debug] 9301#0: *4558 http client request body rest
0
2011/05/15 12:43:32 [debug] 9301#0: *4558 http init upstream, client
timer: 0
2011/05/15 12:43:32 [debug] 9301#0: *4558 epoll add event: fd:10 op:3
ev:80000005
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script copy:
"SCRIPT_FILENAME"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script var:
"/home/www/example.com/htdocs"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script var: "/index.php"
2011/05/15 12:43:32 [debug] 9301#0: *4558 fastcgi param:
"SCRIPT_FILENAME: /home/www/example.com/htdocs/index.php"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script copy:
"QUERY_STRING"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script var:
"taigachat/list.json"
2011/05/15 12:43:32 [debug] 9301#0: *4558 fastcgi param: "QUERY_STRING:
taigachat/list.json"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script copy:
"REQUEST_METHOD"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script var: "POST"
2011/05/15 12:43:32 [debug] 9301#0: *4558 fastcgi param:
"REQUEST_METHOD: POST"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script copy:
"CONTENT_TYPE"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script var:
"application/x-www-form-urlencoded"
2011/05/15 12:43:32 [debug] 9301#0: *4558 fastcgi param: "CONTENT_TYPE:
application/x-www-form-urlencoded"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script copy:
"CONTENT_LENGTH"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script var: "142"
2011/05/15 12:43:32 [debug] 9301#0: *4558 fastcgi param:
"CONTENT_LENGTH: 142"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script copy:
"SCRIPT_NAME"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script var: "/index.php"
2011/05/15 12:43:32 [debug] 9301#0: *4558 fastcgi param: "SCRIPT_NAME:
/index.php"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script copy:
"REQUEST_URI"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script var:
"/index.php?taigachat/list.json"
2011/05/15 12:43:32 [debug] 9301#0: *4558 fastcgi param: "REQUEST_URI:
/index.php?taigachat/list.json"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script copy:
"DOCUMENT_URI"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script var: "/index.php"
2011/05/15 12:43:32 [debug] 9301#0: *4558 fastcgi param: "DOCUMENT_URI:
/index.php"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script copy:
"DOCUMENT_ROOT"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script var:
"/home/www/example.com/htdocs"
2011/05/15 12:43:32 [debug] 9301#0: *4558 fastcgi param: "DOCUMENT_ROOT:
/home/www/example.com/htdocs"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script copy:
"SERVER_PROTOCOL"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script var: "HTTP/1.1"
2011/05/15 12:43:32 [debug] 9301#0: *4558 fastcgi param:
"SERVER_PROTOCOL: HTTP/1.1"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script copy:
"GATEWAY_INTERFACE"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script copy: "CGI/1.1"
2011/05/15 12:43:32 [debug] 9301#0: *4558 fastcgi param:
"GATEWAY_INTERFACE: CGI/1.1"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script copy:
"SERVER_SOFTWARE"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script copy: "nginx/"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script var: "1.0.2"
2011/05/15 12:43:32 [debug] 9301#0: *4558 fastcgi param:
"SERVER_SOFTWARE: nginx/1.0.2"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script copy:
"REMOTE_ADDR"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script var: "[CLIENT IP
ADDRESS]"
2011/05/15 12:43:32 [debug] 9301#0: *4558 fastcgi param: "REMOTE_ADDR:
[CLIENT IP ADDRESS]"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script copy:
"REMOTE_PORT"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script var: "50294"
2011/05/15 12:43:32 [debug] 9301#0: *4558 fastcgi param: "REMOTE_PORT:
50294"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script copy:
"SERVER_ADDR"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script var: "[SERVER IP
ADDRESS]"
2011/05/15 12:43:32 [debug] 9301#0: *4558 fastcgi param: "SERVER_ADDR:
[SERVER IP ADDRESS]"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script copy:
"SERVER_PORT"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script var: "80"
2011/05/15 12:43:32 [debug] 9301#0: *4558 fastcgi param: "SERVER_PORT:
80"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script copy:
"SERVER_NAME"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script var:
"example.com"
2011/05/15 12:43:32 [debug] 9301#0: *4558 fastcgi param: "SERVER_NAME:
example.com"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script copy:
"REDIRECT_STATUS"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http script copy: "200"
2011/05/15 12:43:32 [debug] 9301#0: *4558 fastcgi param:
"REDIRECT_STATUS: 200"
2011/05/15 12:43:32 [debug] 9301#0: *4558 fastcgi param: "HTTP_HOST:
example.com"
2011/05/15 12:43:32 [debug] 9301#0: *4558 fastcgi param:
"HTTP_CONNECTION: keep-alive"
2011/05/15 12:43:32 [debug] 9301#0: *4558 fastcgi param: "HTTP_REFERER:
http://example.com/forum/"
2011/05/15 12:43:32 [debug] 9301#0: *4558 fastcgi param:
"HTTP_CONTENT_LENGTH: 142"
2011/05/15 12:43:32 [debug] 9301#0: *4558 fastcgi param: "HTTP_ORIGIN:
http://example.com"
2011/05/15 12:43:32 [debug] 9301#0: *4558 fastcgi param:
"HTTP_X_REQUESTED_WITH: XMLHttpRequest"
2011/05/15 12:43:32 [debug] 9301#0: *4558 fastcgi param:
"HTTP_USER_AGENT: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/534.24
(KHTML, like Gecko) Chrome/11.0.696.65 Safari/534.24"
2011/05/15 12:43:32 [debug] 9301#0: *4558 fastcgi param:
"HTTP_CONTENT_TYPE: application/x-www-form-urlencoded"
2011/05/15 12:43:32 [debug] 9301#0: *4558 fastcgi param: "HTTP_ACCEPT:
application/json, text/javascript, */*; q=0.01"
2011/05/15 12:43:32 [debug] 9301#0: *4558 fastcgi param:
"HTTP_ACCEPT_ENCODING: gzip,deflate"
2011/05/15 12:43:32 [debug] 9301#0: *4558 fastcgi param:
"HTTP_ACCEPT_LANGUAGE: da-DK,da;q=0.8,en-US;q=0.6,en;q=0.4"
2011/05/15 12:43:32 [debug] 9301#0: *4558 fastcgi param:
"HTTP_ACCEPT_CHARSET: ISO-8859-1,utf-8;q=0.7,*;q=0.3"
2011/05/15 12:43:32 [debug] 9301#0: *4558 fastcgi param: "HTTP_COOKIE:
__utmz=206500500.1304337103.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none);
xf_user=1931%2C8b0bad949f0d38b81a46469cb9a941ec05485539;
xf_session=094d80a983afbbd15ac06937d4b23798;
__utma=206500500.1451942054.1304337103.1305433729.1305437755.69;
__utmc=206500500; __utmb=206500500.3.10.1305437755"
2011/05/15 12:43:32 [debug] 9301#0: *4558 posix_memalign: 0894C380:4096
@16
2011/05/15 12:43:32 [debug] 9301#0: *4558 http cleanup add: 0894C400
2011/05/15 12:43:32 [debug] 9301#0: *4558 get rr peer, try: 1
2011/05/15 12:43:32 [debug] 9301#0: *4558 socket 14
2011/05/15 12:43:32 [debug] 9301#0: *4558 epoll add connection: fd:14
ev:80000005
2011/05/15 12:43:32 [debug] 9301#0: *4558 connect to
unix:/var/run/php-fpm.sock, fd:14 #4559
2011/05/15 12:43:32 [debug] 9301#0: *4558 connected
2011/05/15 12:43:32 [debug] 9301#0: *4558 http upstream connect: 0
2011/05/15 12:43:32 [debug] 9301#0: *4558 http upstream send request
2011/05/15 12:43:32 [debug] 9301#0: *4558 chain writer buf fl:0 s:1448
2011/05/15 12:43:32 [debug] 9301#0: *4558 chain writer buf fl:0 s:137
2011/05/15 12:43:32 [debug] 9301#0: *4558 chain writer buf fl:0 s:15
2011/05/15 12:43:32 [debug] 9301#0: *4558 chain writer buf fl:0 s:5
2011/05/15 12:43:32 [debug] 9301#0: *4558 chain writer buf fl:0 s:11
2011/05/15 12:43:32 [debug] 9301#0: *4558 chain writer in: 0894C444
2011/05/15 12:43:32 [debug] 9301#0: *4558 writev: 1616
2011/05/15 12:43:32 [debug] 9301#0: *4558 chain writer out: 00000000
2011/05/15 12:43:32 [debug] 9301#0: *4558 event timer add: 14:
180000:4088501848
2011/05/15 12:43:32 [debug] 9301#0: *4558 http finalize request: -4,
"/index.php?taigachat/list.json" a:1, c:2
2011/05/15 12:43:32 [debug] 9301#0: *4558 http request count:2 blk:0
2011/05/15 12:43:32 [debug] 9301#0: posted event 00000000
2011/05/15 12:43:32 [debug] 9301#0: worker cycle
2011/05/15 12:43:32 [debug] 9301#0: accept mutex locked
2011/05/15 12:43:32 [debug] 9301#0: epoll timer: 198
2011/05/15 12:43:32 [debug] 9301#0: epoll: fd:10 ev:0004 d:08992435
2011/05/15 12:43:32 [debug] 9301#0: *4558 post event 089B80B4
2011/05/15 12:43:32 [debug] 9301#0: epoll: fd:14 ev:0004 d:08992F89
2011/05/15 12:43:32 [debug] 9301#0: *4558 post event 089B8698
2011/05/15 12:43:32 [debug] 9301#0: timer delta: 1
2011/05/15 12:43:32 [debug] 9301#0: posted events 089B8698
2011/05/15 12:43:32 [debug] 9301#0: posted event 089B8698
2011/05/15 12:43:32 [debug] 9301#0: *4558 delete posted event 089B8698
2011/05/15 12:43:32 [debug] 9301#0: *4558 http upstream request:
"/index.php?taigachat/list.json"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http upstream dummy handler
2011/05/15 12:43:32 [debug] 9301#0: posted event 089B80B4
2011/05/15 12:43:32 [debug] 9301#0: *4558 delete posted event 089B80B4
2011/05/15 12:43:32 [debug] 9301#0: *4558 http run request:
"/index.php?taigachat/list.json"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http request empty handler
2011/05/15 12:43:32 [debug] 9301#0: posted event 00000000
2011/05/15 12:43:32 [debug] 9301#0: worker cycle
2011/05/15 12:43:32 [debug] 9301#0: accept mutex locked
2011/05/15 12:43:32 [debug] 9301#0: epoll timer: 197
2011/05/15 12:43:32 [debug] 9301#0: epoll: fd:10 ev:0005 d:08992435
2011/05/15 12:43:32 [debug] 9301#0: *4558 post event 089AB0AC
2011/05/15 12:43:32 [debug] 9301#0: *4558 post event 089B80B4
2011/05/15 12:43:32 [debug] 9301#0: timer delta: 0
2011/05/15 12:43:32 [debug] 9301#0: posted events 089B80B4
2011/05/15 12:43:32 [debug] 9301#0: posted event 089B80B4
2011/05/15 12:43:32 [debug] 9301#0: *4558 delete posted event 089B80B4
2011/05/15 12:43:32 [debug] 9301#0: *4558 http run request:
"/index.php?taigachat/list.json"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http request empty handler
2011/05/15 12:43:32 [debug] 9301#0: posted event 089AB0AC
2011/05/15 12:43:32 [debug] 9301#0: *4558 delete posted event 089AB0AC
2011/05/15 12:43:32 [debug] 9301#0: *4558 http run request:
"/index.php?taigachat/list.json"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http read client request body
2011/05/15 12:43:32 [debug] 9301#0: *4558 add cleanup: 0894C52C
2011/05/15 12:43:32 [debug] 9301#0: *4558 hashed path:
/var/lib/nginx/body/0000000002
2011/05/15 12:43:32 [debug] 9301#0: *4558 temp fd:15
2011/05/15 12:43:32 [warn] 9301#0: *4558 a client request body is
buffered to a temporary file /var/lib/nginx/body/0000000002 while
sending request to upstream, client: [CLIENT IP ADDRESS], server:
example.com, request: "POST /index.php?taigachat/list.json HTTP/1.1",
upstream: "fastcgi://unix:/var/run/php-fpm.sock:", host: "example.com",
referrer: "http://example.com/forum/"
2011/05/15 12:43:32 [debug] 9301#0: *4558 write: 15, 0894B890, 5, 0
2011/05/15 12:43:32 [debug] 9301#0: *4558 recv: fd:10 0 of 0
2011/05/15 12:43:32 [debug] 9301#0: *4558 http client request body recv
0
2011/05/15 12:43:32 [info] 9301#0: *4558 client closed prematurely
connection while sending request to upstream, client: [CLIENT IP
ADDRESS], server: example.com, request: "POST
/index.php?taigachat/list.json HTTP/1.1", upstream:
"fastcgi://unix:/var/run/php-fpm.sock:", host: "example.com", referrer:
"http://example.com/forum/"
2011/05/15 12:43:32 [debug] 9301#0: *4558 http finalize request: 400,
"/index.php?taigachat/list.json" a:1, c:1
2011/05/15 12:43:32 [debug] 9301#0: *4558 http terminate request
count:1
2011/05/15 12:43:32 [debug] 9301#0: *4558 cleanup http upstream request:
"/index.php"
2011/05/15 12:43:32 [debug] 9301#0: *4558 finalize http upstream
request: -4
2011/05/15 12:43:32 [debug] 9301#0: *4558 finalize http fastcgi request
2011/05/15 12:43:32 [debug] 9301#0: *4558 free rr peer 1 0
2011/05/15 12:43:32 [debug] 9301#0: *4558 close http upstream
connection: 14
2011/05/15 12:43:32 [debug] 9301#0: *4558 event timer del: 14:
4088501848
2011/05/15 12:43:32 [debug] 9301#0: *4558 reusable connection: 0
2011/05/15 12:43:32 [debug] 9301#0: *4558 http finalize request: -4,
"/index.php?taigachat/list.json" a:1, c:1
2011/05/15 12:43:32 [debug] 9301#0: *4558 set http keepalive handler
2011/05/15 12:43:32 [debug] 9301#0: *4558 http close request
2011/05/15 12:43:32 [debug] 9301#0: *4558 http log handler
2011/05/15 12:43:32 [debug] 9301#0: *4558 run cleanup: 0894C52C
2011/05/15 12:43:32 [debug] 9301#0: *4558 file cleanup: fd:15
2011/05/15 12:43:32 [debug] 9301#0: *4558 free: 0894AF70, unused: 5
2011/05/15 12:43:32 [debug] 9301#0: *4558 free: 0894C380, unused: 3417
2011/05/15 12:43:32 [debug] 9301#0: *4558 event timer add: 10:
5000:4088326849
2011/05/15 12:43:32 [debug] 9301#0: *4558 free: 08985548
2011/05/15 12:43:32 [debug] 9301#0: *4558 free: 08983960
2011/05/15 12:43:32 [debug] 9301#0: *4558 hc free: 00000000 0
2011/05/15 12:43:32 [debug] 9301#0: *4558 hc busy: 00000000 0
2011/05/15 12:43:32 [debug] 9301#0: *4558 tcp_nodelay
2011/05/15 12:43:32 [debug] 9301#0: *4558 reusable connection: 1
2011/05/15 12:43:32 [notice] 9299#0: signal 17 (SIGCHLD) received
2011/05/15 12:43:32 [alert] 9299#0: worker process 9301 exited on signal
11 (core dumped)
2011/05/15 12:43:32 [debug] 9299#0: wake up, sigio 0
2011/05/15 12:43:32 [debug] 9299#0: reap children
2011/05/15 12:43:32 [debug] 9299#0: child: 0 9812 e:0 t:0 d:0 r:1 j:0
2011/05/15 12:43:32 [debug] 9299#0: child: 1 9301 e:0 t:1 d:0 r:1 j:0
2011/05/15 12:43:32 [debug] 9299#0: pass close channel s:1 pid:9301
to:9812
2011/05/15 12:43:32 [debug] 9299#0: channel 10:11
2011/05/15 12:43:32 [debug] 9812#0: epoll: fd:9 ev:0001 d:08991D2C
2011/05/15 12:43:32 [debug] 9812#0: channel handler
2011/05/15 12:43:32 [debug] 9812#0: channel: 16
2011/05/15 12:43:32 [debug] 9812#0: channel command: 2
2011/05/15 12:43:32 [debug] 9812#0: close channel s:1 pid:9301 our:9301
fd:10
2011/05/15 12:43:32 [debug] 9812#0: channel: -2
2011/05/15 12:43:32 [debug] 9812#0: timer delta: 112
2011/05/15 12:43:32 [debug] 9812#0: posted events 00000000
2011/05/15 12:43:32 [debug] 9812#0: worker cycle
2011/05/15 12:43:32 [debug] 9812#0: accept mutex locked
2011/05/15 12:43:32 [debug] 9812#0: epoll add event: fd:8 op:1
ev:00000001
2011/05/15 12:43:32 [debug] 9812#0: epoll timer: -1
2011/05/15 12:43:32 [notice] 9299#0: start worker process 9813
2011/05/15 12:43:32 [debug] 9299#0: pass channel s:1 pid:9813 fd:10 to
s:0 pid:9812 fd:3
2011/05/15 12:43:32 [debug] 9299#0: sigsuspend
2011/05/15 12:43:32 [debug] 9812#0: epoll: fd:9 ev:0001 d:08991D2C
2011/05/15 12:43:32 [debug] 9812#0: post event 089AAD04
2011/05/15 12:43:32 [debug] 9812#0: timer delta: 1
2011/05/15 12:43:32 [notice] 9299#0: signal 29 (SIGIO) received
2011/05/15 12:43:32 [debug] 9812#0: posted events 089AAD04
2011/05/15 12:43:32 [debug] 9299#0: wake up, sigio 0
2011/05/15 12:43:32 [debug] 9812#0: posted event 089AAD04
2011/05/15 12:43:32 [debug] 9299#0: sigsuspend
2011/05/15 12:43:32 [debug] 9812#0: delete posted event 089AAD04
2011/05/15 12:43:32 [debug] 9812#0: channel handler
2011/05/15 12:43:32 [debug] 9812#0: channel: 16
2011/05/15 12:43:32 [debug] 9812#0: channel command: 1
2011/05/15 12:43:32 [debug] 9812#0: get channel s:1 pid:9813 fd:3
2011/05/15 12:43:32 [debug] 9812#0: channel: -2
2011/05/15 12:43:32 [debug] 9812#0: posted event 00000000
2011/05/15 12:43:32 [debug] 9812#0: worker cycle
2011/05/15 12:43:32 [debug] 9812#0: accept mutex locked
2011/05/15 12:43:32 [debug] 9812#0: epoll timer: -1
2011/05/15 12:43:32 [notice] 9813#0: sched_setaffinity(0x0000000A)
2011/05/15 12:43:32 [debug] 9813#0: malloc: 0895AAA8:6144
2011/05/15 12:43:32 [debug] 9813#0: malloc: 08991CC8:102400
2011/05/15 12:43:32 [debug] 9813#0: malloc: 089AACD0:53248
2011/05/15 12:43:32 [debug] 9813#0: malloc: 089B7CD8:53248
2011/05/15 12:43:32 [debug] 9813#0: epoll add event: fd:11 op:1
ev:00000001
2011/05/15 12:43:32 [debug] 9813#0: setproctitle: "nginx: worker
process"
2011/05/15 12:43:32 [debug] 9813#0: worker cycle
2011/05/15 12:43:32 [debug] 9813#0: accept mutex lock failed: 0
2011/05/15 12:43:32 [debug] 9813#0: epoll timer: 500

Posted at Nginx Forum: http://forum.nginx.org/read.php?2,198003,198228#msg-198228

More information about the nginx mailing list