nginx 1.0.2 intermittent segfault error 4

inph nginx-forum at nginx.us
Sun May 15 19:44:17 MSD 2011


During low day time traffic, less than 3 hours after the first segfault
above. Same parent nginx process.

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

# stat core
  File: `core'
  Size: 1515520         Blocks: 2416       IO Block: 4096   regular
file
Device: 807h/2055d      Inode: 18350098    Links: 1
Access: (0600/-rw-------)  Uid: (   48/     www)   Gid: (   48/    
www)
Access: 2011-05-15 15:23:53.000000000 +0000
Modify: 2011-05-15 15:23:53.000000000 +0000
Change: 2011-05-15 15:23:53.000000000 +0000
 Birth: -

# 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

# 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 9813]

warning: Can't read pathname for load map: Input/output error.
[snip no symbols found in libs, identical to previous posts]
Core was generated by `nginx:'.
Program terminated with signal 11, Segmentation fault.
#0  0x08085243 in ngx_http_terminate_request (r=0x894d308, rc=400) at
src/http/ngx_http_request.c:2085
2085        ngx_log_debug2(NGX_LOG_DEBUG_HTTP, r->connection->log, 0,
(gdb) bt
#0  0x08085243 in ngx_http_terminate_request (r=0x894d308, rc=400) at
src/http/ngx_http_request.c:2085
#1  0x08084c91 in ngx_http_finalize_request (r=0x894d308, rc=400) at
src/http/ngx_http_request.c:1912
#2  0x0808dab7 in ngx_http_read_client_request_body_handler
(r=0x894d308) at src/http/ngx_http_request_body.c:254
#3  0x080849ab in ngx_http_request_handler (ev=0x89aad38) 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=1)
    at src/os/unix/ngx_process.c:196
#8  0x080700bd in ngx_reap_children (cycle=0x8946cb8) at
src/os/unix/ngx_process_cycle.c:617
#9  0x0806f26b in ngx_master_process_cycle (cycle=0x8946cb8) at
src/os/unix/ngx_process_cycle.c:180
#10 0x0804c297 in main (argc=1, argv=0xbfdb0fc4) at
src/core/nginx.c:405
(gdb) bt full
#0  0x08085243 in ngx_http_terminate_request (r=0x894d308, rc=400) at
src/http/ngx_http_request.c:2085
        cln = 0x0
        mr = 0x894d308
        e = 0x89850e8
#1  0x08084c91 in ngx_http_finalize_request (r=0x894d308, rc=400) at
src/http/ngx_http_request.c:1912
        c = 0x8991d90
        pr = 0x8991d90
        clcf = 0x894deb4
#2  0x0808dab7 in ngx_http_read_client_request_body_handler
(r=0x894d308) at src/http/ngx_http_request_body.c:254
        rc = 400
#3  0x080849ab in ngx_http_request_handler (ev=0x89aad38) at
src/http/ngx_http_request.c:1800
        c = 0x8991d90
        r = 0x894d308
        ctx = 0x8985110
#4  0x08067f7b in ngx_event_process_posted (cycle=0x8946cb8,
posted=0x80eaaf4) at src/event/ngx_event_posted.c:39
        ev = 0x89aad38
#5  0x08066531 in ngx_process_events_and_timers (cycle=0x8946cb8) at
src/event/ngx_event.c:272
        flags = 3
        timer = 179999
        delta = 1
#6  0x0807051b in ngx_worker_process_cycle (cycle=0x8946cb8, data=0x0)
at src/os/unix/ngx_process_cycle.c:800
        i = 9299
        c = 0xbfdb0c98
#7  0x0806dc5f in ngx_spawn_process (cycle=0x8946cb8, proc=0x807038a
<ngx_worker_process_cycle>, data=0x0, name=0x80d2e2b "worker process",
respawn=1)
    at src/os/unix/ngx_process.c:196
        on = 1
        pid = 0
        s = 1
#8  0x080700bd in ngx_reap_children (cycle=0x8946cb8) at
src/os/unix/ngx_process_cycle.c:617
        i = 1
        n = 2
        live = 1
        ch = {command = 2, pid = 9301, slot = 1, fd = -1}
        ccf = 0xbfdb0d10
#9  0x0806f26b in ngx_master_process_cycle (cycle=0x8946cb8) at
src/os/unix/ngx_process_cycle.c:180
        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 = 1
        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


# cat segfault.log |grep "15:23:53"
2011/05/15 15:23:53 [debug] 9813#0: epoll: fd:10 ev:0001 d:08991D91
2011/05/15 15:23:53 [debug] 9813#0: *7244 post event 089AAD38
2011/05/15 15:23:53 [debug] 9813#0: timer delta: 335
2011/05/15 15:23:53 [debug] 9813#0: posted events 089AAD38
2011/05/15 15:23:53 [debug] 9813#0: posted event 089AAD38
2011/05/15 15:23:53 [debug] 9813#0: *7244 delete posted event 089AAD38
2011/05/15 15:23:53 [debug] 9813#0: *7244 http process request header
line
2011/05/15 15:23:53 [debug] 9813#0: *7244 recv: fd:10 488 of 488
2011/05/15 15:23:53 [debug] 9813#0: *7244 http header: "Accept-Charset:
ISO-8859-1,utf-8;q=0.7,*;q=0.3"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http header: "Cookie:
__utmz=206500500.1304337103.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none);
xf_user=1931%2C8b0bad949f0d38b81a46469cb9a941ec05485539;
xf_session=9e29ef01aa56202856bbf74cbae5aed7;
__utma=206500500.1451942054.1304337103.1305442622.1305444878.71;
__utmc=206500500; __utmb=206500500.7.10.1305444878"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http header done
2011/05/15 15:23:53 [debug] 9813#0: *7244 event timer del: 10:
4097999971
2011/05/15 15:23:53 [debug] 9813#0: *7244 generic phase: 0
2011/05/15 15:23:53 [debug] 9813#0: *7244 rewrite phase: 1
2011/05/15 15:23:53 [debug] 9813#0: *7244 test location: "/"
2011/05/15 15:23:53 [debug] 9813#0: *7244 test location: "forum/"
2011/05/15 15:23:53 [debug] 9813#0: *7244 test location: ~
"\.(jpg|jpeg|gif|css|png|js|ico)$"
2011/05/15 15:23:53 [debug] 9813#0: *7244 test location: ~ "\.php$"
2011/05/15 15:23:53 [debug] 9813#0: *7244 using configuration "\.php$"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http cl:142 max:52428800
2011/05/15 15:23:53 [debug] 9813#0: *7244 rewrite phase: 3
2011/05/15 15:23:53 [debug] 9813#0: *7244 post rewrite phase: 4
2011/05/15 15:23:53 [debug] 9813#0: *7244 generic phase: 5
2011/05/15 15:23:53 [debug] 9813#0: *7244 generic phase: 6
2011/05/15 15:23:53 [debug] 9813#0: *7244 generic phase: 7
2011/05/15 15:23:53 [debug] 9813#0: *7244 access phase: 8
2011/05/15 15:23:53 [debug] 9813#0: *7244 access phase: 9
2011/05/15 15:23:53 [debug] 9813#0: *7244 post access phase: 10
2011/05/15 15:23:53 [debug] 9813#0: *7244 try files phase: 11
2011/05/15 15:23:53 [debug] 9813#0: *7244 http client request body
preread 137
2011/05/15 15:23:53 [debug] 9813#0: *7244 http read client request body
2011/05/15 15:23:53 [debug] 9813#0: *7244 recv: fd:10 5 of 5
2011/05/15 15:23:53 [debug] 9813#0: *7244 http client request body recv
5
2011/05/15 15:23:53 [debug] 9813#0: *7244 http client request body rest
0
2011/05/15 15:23:53 [debug] 9813#0: *7244 http init upstream, client
timer: 0
2011/05/15 15:23:53 [debug] 9813#0: *7244 epoll add event: fd:10 op:3
ev:80000005
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script copy:
"SCRIPT_FILENAME"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script var:
"/home/www/example.com/htdocs"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script var: "/index.php"
2011/05/15 15:23:53 [debug] 9813#0: *7244 fastcgi param:
"SCRIPT_FILENAME: /home/www/example.com/htdocs/index.php"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script copy:
"QUERY_STRING"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script var:
"taigachat/list.json"
2011/05/15 15:23:53 [debug] 9813#0: *7244 fastcgi param: "QUERY_STRING:
taigachat/list.json"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script copy:
"REQUEST_METHOD"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script var: "POST"
2011/05/15 15:23:53 [debug] 9813#0: *7244 fastcgi param:
"REQUEST_METHOD: POST"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script copy:
"CONTENT_TYPE"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script var:
"application/x-www-form-urlencoded"
2011/05/15 15:23:53 [debug] 9813#0: *7244 fastcgi param: "CONTENT_TYPE:
application/x-www-form-urlencoded"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script copy:
"CONTENT_LENGTH"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script var: "142"
2011/05/15 15:23:53 [debug] 9813#0: *7244 fastcgi param:
"CONTENT_LENGTH: 142"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script copy:
"SCRIPT_NAME"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script var: "/index.php"
2011/05/15 15:23:53 [debug] 9813#0: *7244 fastcgi param: "SCRIPT_NAME:
/index.php"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script copy:
"REQUEST_URI"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script var:
"/index.php?taigachat/list.json"
2011/05/15 15:23:53 [debug] 9813#0: *7244 fastcgi param: "REQUEST_URI:
/index.php?taigachat/list.json"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script copy:
"DOCUMENT_URI"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script var: "/index.php"
2011/05/15 15:23:53 [debug] 9813#0: *7244 fastcgi param: "DOCUMENT_URI:
/index.php"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script copy:
"DOCUMENT_ROOT"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script var:
"/home/www/example.com/htdocs"
2011/05/15 15:23:53 [debug] 9813#0: *7244 fastcgi param: "DOCUMENT_ROOT:
/home/www/example.com/htdocs"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script copy:
"SERVER_PROTOCOL"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script var: "HTTP/1.1"
2011/05/15 15:23:53 [debug] 9813#0: *7244 fastcgi param:
"SERVER_PROTOCOL: HTTP/1.1"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script copy:
"GATEWAY_INTERFACE"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script copy: "CGI/1.1"
2011/05/15 15:23:53 [debug] 9813#0: *7244 fastcgi param:
"GATEWAY_INTERFACE: CGI/1.1"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script copy:
"SERVER_SOFTWARE"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script copy: "nginx/"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script var: "1.0.2"
2011/05/15 15:23:53 [debug] 9813#0: *7244 fastcgi param:
"SERVER_SOFTWARE: nginx/1.0.2"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script copy:
"REMOTE_ADDR"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script var: "[CLIENT IP
ADDRESS]"
2011/05/15 15:23:53 [debug] 9813#0: *7244 fastcgi param: "REMOTE_ADDR:
[CLIENT IP ADDRESS]"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script copy:
"REMOTE_PORT"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script var: "52898"
2011/05/15 15:23:53 [debug] 9813#0: *7244 fastcgi param: "REMOTE_PORT:
52898"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script copy:
"SERVER_ADDR"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script var: "[SERVER IP
ADDRESS]"
2011/05/15 15:23:53 [debug] 9813#0: *7244 fastcgi param: "SERVER_ADDR:
[SERVER IP ADDRESS]"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script copy:
"SERVER_PORT"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script var: "80"
2011/05/15 15:23:53 [debug] 9813#0: *7244 fastcgi param: "SERVER_PORT:
80"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script copy:
"SERVER_NAME"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script var:
"example.com"
2011/05/15 15:23:53 [debug] 9813#0: *7244 fastcgi param: "SERVER_NAME:
example.com"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script copy:
"REDIRECT_STATUS"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http script copy: "200"
2011/05/15 15:23:53 [debug] 9813#0: *7244 fastcgi param:
"REDIRECT_STATUS: 200"
2011/05/15 15:23:53 [debug] 9813#0: *7244 fastcgi param: "HTTP_HOST:
example.com"
2011/05/15 15:23:53 [debug] 9813#0: *7244 fastcgi param:
"HTTP_CONNECTION: keep-alive"
2011/05/15 15:23:53 [debug] 9813#0: *7244 fastcgi param: "HTTP_REFERER:
http://example.com/forum/"
2011/05/15 15:23:53 [debug] 9813#0: *7244 fastcgi param:
"HTTP_CONTENT_LENGTH: 142"
2011/05/15 15:23:53 [debug] 9813#0: *7244 fastcgi param: "HTTP_ORIGIN:
http://example.com"
2011/05/15 15:23:53 [debug] 9813#0: *7244 fastcgi param:
"HTTP_X_REQUESTED_WITH: XMLHttpRequest"
2011/05/15 15:23:53 [debug] 9813#0: *7244 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 15:23:53 [debug] 9813#0: *7244 fastcgi param:
"HTTP_CONTENT_TYPE: application/x-www-form-urlencoded"
2011/05/15 15:23:53 [debug] 9813#0: *7244 fastcgi param: "HTTP_ACCEPT:
application/json, text/javascript, */*; q=0.01"
2011/05/15 15:23:53 [debug] 9813#0: *7244 fastcgi param:
"HTTP_ACCEPT_ENCODING: gzip,deflate"
2011/05/15 15:23:53 [debug] 9813#0: *7244 fastcgi param:
"HTTP_ACCEPT_LANGUAGE: da-DK,da;q=0.8,en-US;q=0.6,en;q=0.4"
2011/05/15 15:23:53 [debug] 9813#0: *7244 fastcgi param:
"HTTP_ACCEPT_CHARSET: ISO-8859-1,utf-8;q=0.7,*;q=0.3"
2011/05/15 15:23:53 [debug] 9813#0: *7244 fastcgi param: "HTTP_COOKIE:
__utmz=206500500.1304337103.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none);
xf_user=1931%2C8b0bad949f0d38b81a46469cb9a941ec05485539;
xf_session=9e29ef01aa56202856bbf74cbae5aed7;
__utma=206500500.1451942054.1304337103.1305442622.1305444878.71;
__utmc=206500500; __utmb=206500500.7.10.1305444878"
2011/05/15 15:23:53 [debug] 9813#0: *7244 posix_memalign: 0894E640:4096
@16
2011/05/15 15:23:53 [debug] 9813#0: *7244 http cleanup add: 0894E6C0
2011/05/15 15:23:53 [debug] 9813#0: *7244 get rr peer, try: 1
2011/05/15 15:23:53 [debug] 9813#0: *7244 socket 7
2011/05/15 15:23:53 [debug] 9813#0: *7244 epoll add connection: fd:7
ev:80000005
2011/05/15 15:23:53 [debug] 9813#0: *7244 connect to
unix:/var/run/php-fpm.sock, fd:7 #7245
2011/05/15 15:23:53 [debug] 9813#0: *7244 connected
2011/05/15 15:23:53 [debug] 9813#0: *7244 http upstream connect: 0
2011/05/15 15:23:53 [debug] 9813#0: *7244 http upstream send request
2011/05/15 15:23:53 [debug] 9813#0: *7244 chain writer buf fl:0 s:1448
2011/05/15 15:23:53 [debug] 9813#0: *7244 chain writer buf fl:0 s:137
2011/05/15 15:23:53 [debug] 9813#0: *7244 chain writer buf fl:0 s:15
2011/05/15 15:23:53 [debug] 9813#0: *7244 chain writer buf fl:0 s:5
2011/05/15 15:23:53 [debug] 9813#0: *7244 chain writer buf fl:0 s:11
2011/05/15 15:23:53 [debug] 9813#0: *7244 chain writer in: 0894E704
2011/05/15 15:23:53 [debug] 9813#0: *7244 writev: 1616
2011/05/15 15:23:53 [debug] 9813#0: *7244 chain writer out: 00000000
2011/05/15 15:23:53 [debug] 9813#0: *7244 event timer add: 7:
180000:4098122382
2011/05/15 15:23:53 [debug] 9813#0: *7244 http finalize request: -4,
"/index.php?taigachat/list.json" a:1, c:2
2011/05/15 15:23:53 [debug] 9813#0: *7244 http request count:2 blk:0
2011/05/15 15:23:53 [debug] 9813#0: posted event 00000000
2011/05/15 15:23:53 [debug] 9813#0: worker cycle
2011/05/15 15:23:53 [debug] 9813#0: accept mutex locked
2011/05/15 15:23:53 [debug] 9813#0: epoll timer: 180000
2011/05/15 15:23:53 [debug] 9813#0: epoll: fd:10 ev:0004 d:08991D91
2011/05/15 15:23:53 [debug] 9813#0: *7244 post event 089B7D40
2011/05/15 15:23:53 [debug] 9813#0: epoll: fd:7 ev:0004 d:089920B1
2011/05/15 15:23:53 [debug] 9813#0: *7244 post event 089B7EE0
2011/05/15 15:23:53 [debug] 9813#0: timer delta: 1
2011/05/15 15:23:53 [debug] 9813#0: posted events 089B7EE0
2011/05/15 15:23:53 [debug] 9813#0: posted event 089B7EE0
2011/05/15 15:23:53 [debug] 9813#0: *7244 delete posted event 089B7EE0
2011/05/15 15:23:53 [debug] 9813#0: *7244 http upstream request:
"/index.php?taigachat/list.json"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http upstream dummy handler
2011/05/15 15:23:53 [debug] 9813#0: posted event 089B7D40
2011/05/15 15:23:53 [debug] 9813#0: *7244 delete posted event 089B7D40
2011/05/15 15:23:53 [debug] 9813#0: *7244 http run request:
"/index.php?taigachat/list.json"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http request empty handler
2011/05/15 15:23:53 [debug] 9813#0: posted event 00000000
2011/05/15 15:23:53 [debug] 9813#0: worker cycle
2011/05/15 15:23:53 [debug] 9813#0: accept mutex locked
2011/05/15 15:23:53 [debug] 9813#0: epoll timer: 179999
2011/05/15 15:23:53 [debug] 9813#0: epoll: fd:10 ev:0005 d:08991D91
2011/05/15 15:23:53 [debug] 9813#0: *7244 post event 089AAD38
2011/05/15 15:23:53 [debug] 9813#0: *7244 post event 089B7D40
2011/05/15 15:23:53 [debug] 9813#0: timer delta: 1
2011/05/15 15:23:53 [debug] 9813#0: posted events 089B7D40
2011/05/15 15:23:53 [debug] 9813#0: posted event 089B7D40
2011/05/15 15:23:53 [debug] 9813#0: *7244 delete posted event 089B7D40
2011/05/15 15:23:53 [debug] 9813#0: *7244 http run request:
"/index.php?taigachat/list.json"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http request empty handler
2011/05/15 15:23:53 [debug] 9813#0: posted event 089AAD38
2011/05/15 15:23:53 [debug] 9813#0: *7244 delete posted event 089AAD38
2011/05/15 15:23:53 [debug] 9813#0: *7244 http run request:
"/index.php?taigachat/list.json"
2011/05/15 15:23:53 [debug] 9813#0: *7244 http read client request body
2011/05/15 15:23:53 [debug] 9813#0: *7244 add cleanup: 0894E7EC
2011/05/15 15:23:53 [debug] 9813#0: *7244 hashed path:
/var/lib/nginx/body/0000000004
2011/05/15 15:23:53 [debug] 9813#0: *7244 temp fd:14
2011/05/15 15:23:53 [warn] 9813#0: *7244 a client request body is
buffered to a temporary file /var/lib/nginx/body/0000000004 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 15:23:53 [debug] 9813#0: *7244 write: 14, 0894DF40, 5, 0
2011/05/15 15:23:53 [debug] 9813#0: *7244 recv: fd:10 0 of 0
2011/05/15 15:23:53 [debug] 9813#0: *7244 http client request body recv
0
2011/05/15 15:23:53 [info] 9813#0: *7244 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 15:23:53 [debug] 9813#0: *7244 http finalize request: 400,
"/index.php?taigachat/list.json" a:1, c:1
2011/05/15 15:23:53 [debug] 9813#0: *7244 http terminate request
count:1
2011/05/15 15:23:53 [debug] 9813#0: *7244 cleanup http upstream request:
"/index.php"
2011/05/15 15:23:53 [debug] 9813#0: *7244 finalize http upstream
request: -4
2011/05/15 15:23:53 [debug] 9813#0: *7244 finalize http fastcgi request
2011/05/15 15:23:53 [debug] 9813#0: *7244 free rr peer 1 0
2011/05/15 15:23:53 [debug] 9813#0: *7244 close http upstream
connection: 7
2011/05/15 15:23:53 [debug] 9813#0: *7244 event timer del: 7:
4098122382
2011/05/15 15:23:53 [debug] 9813#0: *7244 reusable connection: 0
2011/05/15 15:23:53 [debug] 9813#0: *7244 http finalize request: -4,
"/index.php?taigachat/list.json" a:1, c:1
2011/05/15 15:23:53 [debug] 9813#0: *7244 set http keepalive handler
2011/05/15 15:23:53 [debug] 9813#0: *7244 http close request
2011/05/15 15:23:53 [debug] 9813#0: *7244 http log handler
2011/05/15 15:23:53 [debug] 9813#0: *7244 run cleanup: 0894E7EC
2011/05/15 15:23:53 [debug] 9813#0: *7244 file cleanup: fd:14
2011/05/15 15:23:53 [debug] 9813#0: *7244 free: 0894D620, unused: 5
2011/05/15 15:23:53 [debug] 9813#0: *7244 free: 0894E640, unused: 3417
2011/05/15 15:23:53 [debug] 9813#0: *7244 event timer add: 10:
5000:4097947384
2011/05/15 15:23:53 [debug] 9813#0: *7244 free: 0894D308
2011/05/15 15:23:53 [debug] 9813#0: *7244 free: 089855B8
2011/05/15 15:23:53 [debug] 9813#0: *7244 hc free: 00000000 0
2011/05/15 15:23:53 [debug] 9813#0: *7244 hc busy: 00000000 0
2011/05/15 15:23:53 [debug] 9813#0: *7244 tcp_nodelay
2011/05/15 15:23:53 [debug] 9813#0: *7244 reusable connection: 1
2011/05/15 15:23:53 [notice] 9299#0: signal 17 (SIGCHLD) received
2011/05/15 15:23:53 [alert] 9299#0: worker process 9813 exited on signal
11 (core dumped)
2011/05/15 15:23:53 [debug] 9299#0: wake up, sigio 0
2011/05/15 15:23:53 [debug] 9299#0: reap children
2011/05/15 15:23:53 [debug] 9299#0: child: 0 9812 e:0 t:0 d:0 r:1 j:0
2011/05/15 15:23:53 [debug] 9299#0: child: 1 9813 e:0 t:1 d:0 r:1 j:0
2011/05/15 15:23:53 [debug] 9299#0: pass close channel s:1 pid:9813
to:9812
2011/05/15 15:23:53 [debug] 9299#0: channel 7:10
2011/05/15 15:23:53 [notice] 9299#0: start worker process 10069
2011/05/15 15:23:53 [debug] 9299#0: pass channel s:1 pid:10069 fd:7 to
s:0 pid:9812 fd:3
2011/05/15 15:23:53 [debug] 9299#0: sigsuspend
2011/05/15 15:23:53 [debug] 9812#0: epoll: fd:9 ev:0001 d:08991D2C
2011/05/15 15:23:53 [debug] 9812#0: channel handler
2011/05/15 15:23:53 [debug] 9812#0: channel: 16
2011/05/15 15:23:53 [debug] 9812#0: channel command: 2
2011/05/15 15:23:53 [debug] 9812#0: close channel s:1 pid:9813 our:9813
fd:3
2011/05/15 15:23:53 [debug] 9812#0: channel: 16
2011/05/15 15:23:53 [debug] 9812#0: channel command: 1
2011/05/15 15:23:53 [debug] 9812#0: get channel s:1 pid:10069 fd:3
2011/05/15 15:23:53 [debug] 9812#0: channel: -2
2011/05/15 15:23:53 [debug] 9812#0: timer delta: 243
2011/05/15 15:23:53 [debug] 9812#0: posted events 00000000
2011/05/15 15:23:53 [debug] 9812#0: worker cycle
2011/05/15 15:23:53 [debug] 9812#0: accept mutex locked
2011/05/15 15:23:53 [debug] 9812#0: epoll add event: fd:8 op:1
ev:00000001
2011/05/15 15:23:53 [debug] 9812#0: epoll timer: -1
2011/05/15 15:23:53 [notice] 9299#0: signal 29 (SIGIO) received
2011/05/15 15:23:53 [debug] 9299#0: wake up, sigio 0
2011/05/15 15:23:53 [debug] 9299#0: sigsuspend
2011/05/15 15:23:53 [notice] 10069#0: sched_setaffinity(0x0000000A)
2011/05/15 15:23:53 [debug] 10069#0: malloc: 0895AAA8:6144
2011/05/15 15:23:53 [debug] 10069#0: malloc: 08991CC8:102400
2011/05/15 15:23:53 [debug] 10069#0: malloc: 089AACD0:53248
2011/05/15 15:23:53 [debug] 10069#0: malloc: 089B7CD8:53248
2011/05/15 15:23:53 [debug] 10069#0: epoll add event: fd:10 op:1
ev:00000001
2011/05/15 15:23:53 [debug] 10069#0: setproctitle: "nginx: worker
process"
2011/05/15 15:23:53 [debug] 10069#0: worker cycle
2011/05/15 15:23:53 [debug] 10069#0: accept mutex lock failed: 0
2011/05/15 15:23:53 [debug] 10069#0: epoll timer: 500
2011/05/15 15:23:53 [debug] 10069#0: timer delta: 503
2011/05/15 15:23:53 [debug] 10069#0: posted events 00000000
2011/05/15 15:23:53 [debug] 10069#0: worker cycle
2011/05/15 15:23:53 [debug] 10069#0: accept mutex lock failed: 0
2011/05/15 15:23:53 [debug] 10069#0: epoll timer: 500

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




More information about the nginx mailing list