nginx-ajp-dump

nginx.debug.log

2014/05/19 22:26:57 [debug] 17235#0: bind() 0.0.0.0:80 #6 
2014/05/19 22:26:57 [notice] 17235#0: using the "epoll" event method
2014/05/19 22:26:57 [debug] 17235#0: counter: 00007FAA59195080, 1
2014/05/19 22:26:57 [notice] 17235#0: nginx/1.6.0
2014/05/19 22:26:57 [notice] 17235#0: built by gcc 4.4.7 20120313 (Red Hat 4.4.7-4) (GCC) 
2014/05/19 22:26:57 [notice] 17235#0: OS: Linux 2.6.32-431.el6.x86_64
2014/05/19 22:26:57 [notice] 17235#0: getrlimit(RLIMIT_NOFILE): 1024:4096
2014/05/19 22:26:57 [debug] 17235#0: write: 7, 00007FFFD4159CB0, 6, 0
2014/05/19 22:26:57 [debug] 17235#0: setproctitle: "nginx: master process nginx.debug"
2014/05/19 22:26:57 [notice] 17235#0: start worker processes
2014/05/19 22:26:57 [debug] 17235#0: channel 3:7
2014/05/19 22:26:57 [notice] 17235#0: start worker process 17237
2014/05/19 22:26:57 [debug] 17235#0: channel 8:9
2014/05/19 22:26:57 [notice] 17235#0: start cache manager process 17238
2014/05/19 22:26:57 [debug] 17235#0: pass channel s:1 pid:17238 fd:8 to s:0 pid:17237 fd:3
2014/05/19 22:26:57 [debug] 17235#0: channel 10:11
2014/05/19 22:26:57 [notice] 17235#0: start cache loader process 17239
2014/05/19 22:26:57 [debug] 17235#0: pass channel s:2 pid:17239 fd:10 to s:0 pid:17237 fd:3
2014/05/19 22:26:57 [debug] 17235#0: pass channel s:2 pid:17239 fd:10 to s:1 pid:17238 fd:8
2014/05/19 22:26:57 [debug] 17235#0: sigsuspend
2014/05/19 22:26:57 [debug] 17239#0: close listening 0.0.0.0:80 #6 
2014/05/19 22:26:57 [debug] 17239#0: eventfd: 12
2014/05/19 22:26:57 [debug] 17239#0: malloc: 0000000001E942D0:6144
2014/05/19 22:26:57 [debug] 17239#0: malloc: 0000000001EB3EB0:110592
2014/05/19 22:26:57 [debug] 17239#0: malloc: 0000000001ECEEC0:53248
2014/05/19 22:26:57 [debug] 17238#0: close listening 0.0.0.0:80 #6 
2014/05/19 22:26:57 [debug] 17238#0: eventfd: 10
2014/05/19 22:26:57 [debug] 17239#0: malloc: 0000000001EDBED0:53248
2014/05/19 22:26:57 [debug] 17239#0: epoll add event: fd:11 op:1 ev:00002001
2014/05/19 22:26:57 [debug] 17238#0: malloc: 0000000001E942D0:6144
2014/05/19 22:26:57 [debug] 17238#0: malloc: 0000000001EB3EB0:110592
2014/05/19 22:26:57 [debug] 17239#0: setproctitle: "nginx: cache loader process"
2014/05/19 22:26:57 [debug] 17239#0: event timer add: -1: 60000:1400563677355
2014/05/19 22:26:57 [debug] 17238#0: malloc: 0000000001ECEEC0:53248
2014/05/19 22:26:57 [debug] 17239#0: epoll timer: 60000
2014/05/19 22:26:57 [debug] 17238#0: malloc: 0000000001EDBED0:53248
2014/05/19 22:26:57 [debug] 17238#0: epoll add event: fd:9 op:1 ev:00002001
2014/05/19 22:26:57 [debug] 17238#0: setproctitle: "nginx: cache manager process"
2014/05/19 22:26:57 [debug] 17238#0: event timer add: -1: 0:1400563617355
2014/05/19 22:26:57 [debug] 17238#0: epoll timer: 0
2014/05/19 22:26:57 [debug] 17238#0: epoll: fd:9 ev:0001 d:0000000001EB3EB0
2014/05/19 22:26:57 [debug] 17238#0: channel handler
2014/05/19 22:26:57 [debug] 17238#0: channel: 32
2014/05/19 22:26:57 [debug] 17238#0: channel command: 1
2014/05/19 22:26:57 [debug] 17238#0: get channel s:2 pid:17239 fd:7
2014/05/19 22:26:57 [debug] 17238#0: channel: -2
2014/05/19 22:26:57 [debug] 17238#0: timer delta: 5
2014/05/19 22:26:57 [debug] 17238#0: event timer del: -1: 1400563617355
2014/05/19 22:26:57 [debug] 17238#0: http file cache expire
2014/05/19 22:26:57 [debug] 17238#0: malloc: 0000000001EA2A80:65
2014/05/19 22:26:57 [debug] 17238#0: shmtx lock
2014/05/19 22:26:57 [debug] 17238#0: shmtx unlock
2014/05/19 22:26:57 [debug] 17238#0: shmtx lock
2014/05/19 22:26:57 [debug] 17238#0: shmtx unlock
2014/05/19 22:26:57 [debug] 17238#0: http file cache size: 0
2014/05/19 22:26:57 [debug] 17238#0: event timer add: -1: 10000:1400563627361
2014/05/19 22:26:57 [debug] 17238#0: posted events 0000000000000000
2014/05/19 22:26:57 [debug] 17238#0: epoll timer: 10000
2014/05/19 22:26:57 [debug] 17237#0: eventfd: 9
2014/05/19 22:26:57 [debug] 17237#0: malloc: 0000000001E942D0:6144
2014/05/19 22:26:57 [debug] 17237#0: malloc: 00007FAA59146010:221184
2014/05/19 22:26:57 [debug] 17237#0: malloc: 0000000001EB3EB0:106496
2014/05/19 22:26:57 [debug] 17237#0: malloc: 0000000001ECDEC0:106496
2014/05/19 22:26:57 [debug] 17237#0: epoll add event: fd:6 op:1 ev:00002001
2014/05/19 22:26:57 [debug] 17237#0: epoll add event: fd:7 op:1 ev:00002001
2014/05/19 22:26:57 [debug] 17237#0: setproctitle: "nginx: worker process"
2014/05/19 22:26:57 [debug] 17237#0: worker cycle
2014/05/19 22:26:57 [debug] 17237#0: epoll timer: -1
2014/05/19 22:26:57 [debug] 17237#0: epoll: fd:7 ev:0001 d:00007FAA591460E8
2014/05/19 22:26:57 [debug] 17237#0: channel handler
2014/05/19 22:26:57 [debug] 17237#0: channel: 32
2014/05/19 22:26:57 [debug] 17237#0: channel command: 1
2014/05/19 22:26:57 [debug] 17237#0: get channel s:1 pid:17238 fd:3
2014/05/19 22:26:57 [debug] 17237#0: channel: 32
2014/05/19 22:26:57 [debug] 17237#0: channel command: 1
2014/05/19 22:26:57 [debug] 17237#0: get channel s:2 pid:17239 fd:10
2014/05/19 22:26:57 [debug] 17237#0: channel: -2
2014/05/19 22:26:57 [debug] 17237#0: timer delta: 6
2014/05/19 22:26:57 [debug] 17237#0: posted events 0000000000000000
2014/05/19 22:26:57 [debug] 17237#0: worker cycle
2014/05/19 22:26:57 [debug] 17237#0: epoll timer: -1
2014/05/19 22:27:04 [debug] 17237#0: epoll: fd:6 ev:0001 d:00007FAA59146010
2014/05/19 22:27:04 [debug] 17237#0: accept on 0.0.0.0:80, ready: 0
2014/05/19 22:27:04 [debug] 17237#0: posix_memalign: 0000000001E89030:256 @16
2014/05/19 22:27:04 [debug] 17237#0: *1 accept: 127.0.0.1 fd:11
2014/05/19 22:27:04 [debug] 17237#0: posix_memalign: 0000000001E89190:256 @16
2014/05/19 22:27:04 [debug] 17237#0: *1 event timer add: 11: 60000:1400563684151
2014/05/19 22:27:04 [debug] 17237#0: *1 reusable connection: 1
2014/05/19 22:27:04 [debug] 17237#0: *1 epoll add event: fd:11 op:1 ev:80002001
2014/05/19 22:27:04 [debug] 17237#0: timer delta: 6790
2014/05/19 22:27:04 [debug] 17237#0: posted events 0000000000000000
2014/05/19 22:27:04 [debug] 17237#0: worker cycle
2014/05/19 22:27:04 [debug] 17237#0: epoll timer: 60000
2014/05/19 22:27:04 [debug] 17237#0: epoll: fd:11 ev:0001 d:00007FAA591461C0
2014/05/19 22:27:04 [debug] 17237#0: *1 http wait request handler
2014/05/19 22:27:04 [debug] 17237#0: *1 malloc: 0000000001EA3270:1024
2014/05/19 22:27:04 [debug] 17237#0: *1 recv: fd:11 189 of 1024
2014/05/19 22:27:04 [debug] 17237#0: *1 reusable connection: 0
2014/05/19 22:27:04 [debug] 17237#0: *1 posix_memalign: 0000000001EA88A0:4096 @16
2014/05/19 22:27:04 [debug] 17237#0: *1 http process request line
2014/05/19 22:27:04 [debug] 17237#0: *1 http request line: "GET /solr/admin/solr_small.png HTTP/1.1"
2014/05/19 22:27:04 [debug] 17237#0: *1 http uri: "/solr/admin/solr_small.png"
2014/05/19 22:27:04 [debug] 17237#0: *1 http args: ""
2014/05/19 22:27:04 [debug] 17237#0: *1 http exten: "png"
2014/05/19 22:27:04 [debug] 17237#0: *1 http process request header line
2014/05/19 22:27:04 [debug] 17237#0: *1 http header: "User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.14.0.0 zlib/1.2.3 libidn/1.18 libssh2/1.4.2"
2014/05/19 22:27:04 [debug] 17237#0: *1 http header: "Host: localhost"
2014/05/19 22:27:04 [debug] 17237#0: *1 http header: "Accept: */*"
2014/05/19 22:27:04 [debug] 17237#0: *1 http header done
2014/05/19 22:27:04 [debug] 17237#0: *1 event timer del: 11: 1400563684151
2014/05/19 22:27:04 [debug] 17237#0: *1 generic phase: 0
2014/05/19 22:27:04 [debug] 17237#0: *1 rewrite phase: 1
2014/05/19 22:27:04 [debug] 17237#0: *1 test location: "/"
2014/05/19 22:27:04 [debug] 17237#0: *1 test location: ~ "^/.*\.(gif|jpg|png|js)$"
2014/05/19 22:27:04 [debug] 17237#0: *1 using configuration "^/.*\.(gif|jpg|png|js)$"
2014/05/19 22:27:04 [debug] 17237#0: *1 http cl:-1 max:1048576
2014/05/19 22:27:04 [debug] 17237#0: *1 rewrite phase: 3
2014/05/19 22:27:04 [debug] 17237#0: *1 post rewrite phase: 4
2014/05/19 22:27:04 [debug] 17237#0: *1 generic phase: 5
2014/05/19 22:27:04 [debug] 17237#0: *1 generic phase: 6
2014/05/19 22:27:04 [debug] 17237#0: *1 generic phase: 7
2014/05/19 22:27:04 [debug] 17237#0: *1 access phase: 8
2014/05/19 22:27:04 [debug] 17237#0: *1 access phase: 9
2014/05/19 22:27:04 [debug] 17237#0: *1 access phase: 10
2014/05/19 22:27:04 [debug] 17237#0: *1 access phase: 11
2014/05/19 22:27:04 [debug] 17237#0: *1 post access phase: 12
2014/05/19 22:27:04 [debug] 17237#0: *1 posix_memalign: 0000000001E95AE0:4096 @16
2014/05/19 22:27:04 [debug] 17237#0: *1 http init upstream, client timer: 0
2014/05/19 22:27:04 [debug] 17237#0: *1 epoll add event: fd:11 op:3 ev:80002005
2014/05/19 22:27:04 [debug] 17237#0: *1 http script var: "localhost"
2014/05/19 22:27:04 [debug] 17237#0: *1 http script var: "/solr/admin/solr_small.png"
2014/05/19 22:27:04 [debug] 17237#0: *1 http cache key: "localhost/solr/admin/solr_small.png"
2014/05/19 22:27:04 [debug] 17237#0: *1 add cleanup: 0000000001E96278
2014/05/19 22:27:04 [debug] 17237#0: shmtx lock
2014/05/19 22:27:04 [debug] 17237#0: slab alloc: 112 slot: 4
2014/05/19 22:27:04 [debug] 17237#0: slab alloc: 00007FAA4FFF4080
2014/05/19 22:27:04 [debug] 17237#0: shmtx unlock
2014/05/19 22:27:04 [debug] 17237#0: *1 http file cache exists: -5 e:0
2014/05/19 22:27:04 [debug] 17237#0: *1 cache file: "/var/cache/nginx/ajp_cache/f/66/d6d0ab0da12a1b0634bee1edbd0a466f"
2014/05/19 22:27:04 [debug] 17237#0: *1 add cleanup: 0000000001E962D8
2014/05/19 22:27:04 [debug] 17237#0: *1 http upstream cache: -5
2014/05/19 22:27:04 [debug] 17237#0: *1 malloc: 0000000001E8DC40:8192
2014/05/19 22:27:04 [debug] 17237#0: *1 Into ajp_marshal_into_msgb, uri: "/solr/admin/solr_small.png", version: "HTTP/1.1"
2014/05/19 22:27:04 [debug] 17237#0: *1 ajp_marshal_into_msgb: Header[0] [User-Agent] = [curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.14.0.0 zlib/1.2.3 libidn/1.18 libssh2/1.4.2], size:190
2014/05/19 22:27:04 [debug] 17237#0: *1 ajp_marshal_into_msgb: Header[1] [Host] = [localhost], size:204
2014/05/19 22:27:04 [debug] 17237#0: *1 ajp_marshal_into_msgb: Header[2] [Accept] = [*/*], size:212
2014/05/19 22:27:04 [debug] 17237#0: *1 ajp_marshal_into_msgb: attribute AJP_REMOTE_PORT 57145
2014/05/19 22:27:04 [debug] 17237#0: *1 ajp_marshal_into_msgb: Done, buff_size: 240
2014/05/19 22:27:04 [debug] 17237#0: *1 http cleanup add: 0000000001E963D8
2014/05/19 22:27:04 [debug] 17237#0: *1 get rr peer, try: 1
2014/05/19 22:27:04 [debug] 17237#0: *1 socket 12
2014/05/19 22:27:04 [debug] 17237#0: *1 epoll add connection: fd:12 ev:80002005
2014/05/19 22:27:04 [debug] 17237#0: *1 connect to 137.219.15.172:8009, fd:12 #2
2014/05/19 22:27:04 [debug] 17237#0: *1 http upstream connect: -2
2014/05/19 22:27:04 [debug] 17237#0: *1 posix_memalign: 0000000001EA2A80:128 @16
2014/05/19 22:27:04 [debug] 17237#0: *1 event timer add: 12: 60000:1400563684152
2014/05/19 22:27:04 [debug] 17237#0: *1 http finalize request: -4, "/solr/admin/solr_small.png?" a:1, c:2
2014/05/19 22:27:04 [debug] 17237#0: *1 http request count:2 blk:0
2014/05/19 22:27:04 [debug] 17237#0: timer delta: 1
2014/05/19 22:27:04 [debug] 17237#0: posted events 0000000000000000
2014/05/19 22:27:04 [debug] 17237#0: worker cycle
2014/05/19 22:27:04 [debug] 17237#0: epoll timer: 60000
2014/05/19 22:27:04 [debug] 17237#0: epoll: fd:11 ev:0004 d:00007FAA591461C0
2014/05/19 22:27:04 [debug] 17237#0: *1 http run request: "/solr/admin/solr_small.png?"
2014/05/19 22:27:04 [debug] 17237#0: *1 http upstream check client, write event:1, "/solr/admin/solr_small.png"
2014/05/19 22:27:04 [debug] 17237#0: *1 http upstream recv(): -1 (11: Resource temporarily unavailable)
2014/05/19 22:27:04 [debug] 17237#0: timer delta: 1
2014/05/19 22:27:04 [debug] 17237#0: posted events 0000000000000000
2014/05/19 22:27:04 [debug] 17237#0: worker cycle
2014/05/19 22:27:04 [debug] 17237#0: epoll timer: 59999
2014/05/19 22:27:04 [debug] 17237#0: epoll: fd:12 ev:0004 d:00007FAA59146298
2014/05/19 22:27:04 [debug] 17237#0: *1 http upstream request: "/solr/admin/solr_small.png?"
2014/05/19 22:27:04 [debug] 17237#0: *1 http upstream send request handler
2014/05/19 22:27:04 [debug] 17237#0: *1 http upstream send request
2014/05/19 22:27:04 [debug] 17237#0: *1 chain writer buf fl:1 s:244
2014/05/19 22:27:04 [debug] 17237#0: *1 chain writer in: 0000000001E96410
2014/05/19 22:27:04 [debug] 17237#0: *1 writev: 244
2014/05/19 22:27:04 [debug] 17237#0: *1 chain writer out: 0000000000000000
2014/05/19 22:27:04 [debug] 17237#0: *1 event timer del: 12: 1400563684152
2014/05/19 22:27:04 [debug] 17237#0: *1 event timer add: 12: 90000:1400563714154
2014/05/19 22:27:04 [debug] 17237#0: timer delta: 1
2014/05/19 22:27:04 [debug] 17237#0: posted events 0000000000000000
2014/05/19 22:27:04 [debug] 17237#0: worker cycle
2014/05/19 22:27:04 [debug] 17237#0: epoll timer: 90000
2014/05/19 22:27:04 [debug] 17237#0: epoll: fd:12 ev:0005 d:00007FAA59146298
2014/05/19 22:27:04 [debug] 17237#0: *1 http upstream request: "/solr/admin/solr_small.png?"
2014/05/19 22:27:04 [debug] 17237#0: *1 http upstream process header
2014/05/19 22:27:04 [debug] 17237#0: *1 malloc: 0000000001E8FC50:4096
2014/05/19 22:27:04 [debug] 17237#0: *1 recv: fd:12 7 of 4014
2014/05/19 22:27:04 [debug] 17237#0: *1 ngx_http_ajp_process_header: state(3)
2014/05/19 22:27:04 [debug] 17237#0: *1 ngx_http_ajp_process_header: parse response, pos:0000000001E8FCA2, last:0000000001E8FCA9
2014/05/19 22:27:04 [warn] 17237#0: *1 ngx_http_upstream_send_request_body: bad state(3) while reading response header from upstream, client: 127.0.0.1, server: localhost, request: "GET /solr/admin/solr_small.png HTTP/1.1", upstream: "ajp://137.219.15.172:8009", host: "localhost"
2014/05/19 22:27:04 [debug] 17237#0: *1 chain writer buf fl:0 s:6
2014/05/19 22:27:04 [debug] 17237#0: *1 chain writer in: 0000000001E96610
2014/05/19 22:27:04 [debug] 17237#0: *1 writev: 6
2014/05/19 22:27:04 [debug] 17237#0: *1 chain writer out: 0000000000000000
2014/05/19 22:27:04 [debug] 17237#0: *1 event timer: 12, old: 1400563714154, new: 1400563714156
2014/05/19 22:27:04 [debug] 17237#0: *1 recv: fd:12 4007 of 4007
2014/05/19 22:27:04 [debug] 17237#0: *1 ngx_http_ajp_process_header: state(3)
2014/05/19 22:27:04 [debug] 17237#0: *1 ngx_http_ajp_process_header: parse response, pos:0000000001E8FCA9, last:0000000001E90C50
2014/05/19 22:27:04 [debug] 17237#0: *1 ajp_unmarshal_response
2014/05/19 22:27:04 [debug] 17237#0: *1 ajp_unmarshal_response: status = 200
2014/05/19 22:27:04 [debug] 17237#0: *1 ajp_unmarshal_response: status_line = "200 OK"
2014/05/19 22:27:04 [debug] 17237#0: *1 ajp_unmarshal_response: Number of headers is = 5
2014/05/19 22:27:04 [debug] 17237#0: *1 http ajp unknown header: Accept-Ranges
2014/05/19 22:27:04 [debug] 17237#0: *1 http ajp header: "Accept-Ranges: bytes"
2014/05/19 22:27:04 [debug] 17237#0: *1 http ajp known header: 0000A001
2014/05/19 22:27:04 [debug] 17237#0: *1 http ajp header: "Content-Type: image/png"
2014/05/19 22:27:04 [debug] 17237#0: *1 http ajp known header: 0000A003
2014/05/19 22:27:04 [debug] 17237#0: *1 http ajp header: "Content-Length: 7926"
2014/05/19 22:27:04 [debug] 17237#0: *1 http ajp known header: 0000A005
2014/05/19 22:27:04 [debug] 17237#0: *1 http ajp header: "Last-Modified: Sat, 25 Jun 2011 21:25:52 GMT"
2014/05/19 22:27:04 [debug] 17237#0: *1 http ajp unknown header: Server
2014/05/19 22:27:04 [debug] 17237#0: *1 http ajp header: "Server: Server: Jetty(6.0.x)"
2014/05/19 22:27:04 [debug] 17237#0: *1 xslt filter header
2014/05/19 22:27:04 [debug] 17237#0: *1 HTTP/1.1 200 OK
Server: nginx/1.6.0
Date: Tue, 20 May 2014 05:27:04 GMT
Content-Type: image/png
Content-Length: 7926
Connection: keep-alive
Last-Modified: Sat, 25 Jun 2011 21:25:52 GMT
Accept-Ranges: bytes

2014/05/19 22:27:04 [debug] 17237#0: *1 write new buf t:1 f:0 0000000001E96690, pos 0000000001E96690, size: 216 file: 0, size: 0
2014/05/19 22:27:04 [debug] 17237#0: *1 http write filter: l:0 f:0 s:216
2014/05/19 22:27:04 [debug] 17237#0: *1 http file cache set header
2014/05/19 22:27:04 [debug] 17237#0: *1 http cacheable: 1
2014/05/19 22:27:04 [debug] 17237#0: *1 http upstream process upstream
2014/05/19 22:27:04 [debug] 17237#0: *1 pipe read upstream: 1
2014/05/19 22:27:04 [debug] 17237#0: *1 pipe preread: 3880
2014/05/19 22:27:04 [debug] 17237#0: *1 ngx_http_ajp_input_filter: state(5)
2014/05/19 22:27:04 [debug] 17237#0: *1 input filter packet, begin length: 0, buffer_size: 3880
2014/05/19 22:27:04 [debug] 17237#0: *1 http ajp packet header pstate: 0, byte: 41
2014/05/19 22:27:04 [debug] 17237#0: *1 http ajp packet header pstate: 1, byte: 42
2014/05/19 22:27:04 [debug] 17237#0: *1 http ajp packet header pstate: 2, byte: 1E
2014/05/19 22:27:04 [debug] 17237#0: *1 http ajp packet header pstate: 3, byte: FA
2014/05/19 22:27:04 [debug] 17237#0: *1 http ajp packet header pstate: 4, byte: 03
2014/05/19 22:27:04 [debug] 17237#0: *1 http ajp packet header pstate: 6, byte: 1E
2014/05/19 22:27:04 [debug] 17237#0: *1 http ajp packet header pstate: 7, byte: F6
2014/05/19 22:27:04 [debug] 17237#0: *1 input filter packet, length:7926, buffer_size:3873
2014/05/19 22:27:04 [debug] 17237#0: *1 input buf #0 0000000001E8FD2F size: 3873
2014/05/19 22:27:04 [debug] 17237#0: *1 free buf 0000000001E90C50 0
2014/05/19 22:27:04 [debug] 17237#0: *1 input buf 0000000001E8FD2F 0
2014/05/19 22:27:04 [debug] 17237#0: *1 malloc: 0000000001E90C60:4096
2014/05/19 22:27:04 [debug] 17237#0: *1 readv: 1:4096
2014/05/19 22:27:04 [debug] 17237#0: *1 pipe recv chain: 4060
2014/05/19 22:27:04 [debug] 17237#0: *1 readv: 1:36
2014/05/19 22:27:04 [debug] 17237#0: *1 readv() not ready (11: Resource temporarily unavailable)
2014/05/19 22:27:04 [debug] 17237#0: *1 pipe recv chain: -2
2014/05/19 22:27:04 [debug] 17237#0: *1 pipe buf in   s:1 t:1 f:0 0000000001E8FC50, pos 0000000001E8FD2F, size: 3873 file: 0, size: 0
2014/05/19 22:27:04 [debug] 17237#0: *1 pipe buf free s:0 t:1 f:0 0000000001E90C60, pos 0000000001E90C60, size: 4060 file: 0, size: 0
2014/05/19 22:27:04 [debug] 17237#0: *1 pipe length: 4
2014/05/19 22:27:04 [debug] 17237#0: *1 ngx_http_ajp_input_filter: state(5)
2014/05/19 22:27:04 [debug] 17237#0: *1 input filter packet, begin length: 4053, buffer_size: 4060
2014/05/19 22:27:04 [debug] 17237#0: *1 input filter packet, length:4053, buffer_size:4060
2014/05/19 22:27:04 [debug] 17237#0: *1 input buf #1 0000000001E90C60 size: 4053
2014/05/19 22:27:04 [debug] 17237#0: *1 input filter packet, begin length: 0, buffer_size: 6
2014/05/19 22:27:04 [debug] 17237#0: *1 http ajp packet header pstate: 0, byte: 41
2014/05/19 22:27:04 [debug] 17237#0: *1 http ajp packet header pstate: 1, byte: 42
2014/05/19 22:27:04 [debug] 17237#0: *1 http ajp packet header pstate: 2, byte: 00
2014/05/19 22:27:04 [debug] 17237#0: *1 http ajp packet header pstate: 3, byte: 02
2014/05/19 22:27:04 [debug] 17237#0: *1 http ajp packet header pstate: 4, byte: 05
2014/05/19 22:27:04 [debug] 17237#0: *1 http ajp packet header pstate: 5, byte: 01
2014/05/19 22:27:04 [debug] 17237#0: *1 ngx_http_ajp_end_response: reuse=1
2014/05/19 22:27:04 [debug] 17237#0: *1 free buf 0000000001E91C3C 0
2014/05/19 22:27:04 [debug] 17237#0: *1 input buf 0000000001E90C60 0
2014/05/19 22:27:04 [debug] 17237#0: *1 add cleanup: 0000000001E96A30
2014/05/19 22:27:04 [debug] 17237#0: *1 hashed path: /etc/nginx/ajp_temp/1/00/0000000001
2014/05/19 22:27:04 [debug] 17237#0: *1 temp fd:13
2014/05/19 22:27:04 [debug] 17237#0: *1 writev: 13, 8142
2014/05/19 22:27:04 [debug] 17237#0: *1 pipe write downstream: 1
2014/05/19 22:27:04 [debug] 17237#0: *1 pipe write downstream flush out
2014/05/19 22:27:04 [debug] 17237#0: *1 http output filter "/solr/admin/solr_small.png?"
2014/05/19 22:27:04 [debug] 17237#0: *1 http copy filter: "/solr/admin/solr_small.png?"
2014/05/19 22:27:04 [debug] 17237#0: *1 posix_memalign: 0000000001EE7ED0:4096 @16
2014/05/19 22:27:04 [debug] 17237#0: *1 xslt filter body
2014/05/19 22:27:04 [debug] 17237#0: *1 http postpone filter "/solr/admin/solr_small.png?" 0000000001E96888
2014/05/19 22:27:04 [debug] 17237#0: *1 write old buf t:1 f:0 0000000001E96690, pos 0000000001E96690, size: 216 file: 0, size: 0
2014/05/19 22:27:04 [debug] 17237#0: *1 write new buf t:0 f:1 0000000000000000, pos 0000000000000000, size: 0 file: 216, size: 7926
2014/05/19 22:27:04 [debug] 17237#0: *1 http write filter: l:0 f:0 s:8142
2014/05/19 22:27:04 [debug] 17237#0: *1 http write filter limit 0
2014/05/19 22:27:04 [debug] 17237#0: *1 writev: 216
2014/05/19 22:27:04 [debug] 17237#0: *1 sendfile: @216 7926
2014/05/19 22:27:04 [debug] 17237#0: *1 sendfile: 7926, @216 7926:7926
2014/05/19 22:27:04 [debug] 17237#0: *1 http write filter 0000000000000000
2014/05/19 22:27:04 [debug] 17237#0: *1 http copy filter: 0 "/solr/admin/solr_small.png?"
2014/05/19 22:27:04 [debug] 17237#0: *1 pipe write downstream done
2014/05/19 22:27:04 [debug] 17237#0: *1 event timer: 12, old: 1400563714154, new: 1400563714156
2014/05/19 22:27:04 [debug] 17237#0: *1 http file cache update
2014/05/19 22:27:04 [debug] 17237#0: *1 http file cache rename: "/etc/nginx/ajp_temp/1/00/0000000001" to "/var/cache/nginx/ajp_cache/f/66/d6d0ab0da12a1b0634bee1edbd0a466f"
2014/05/19 22:27:04 [debug] 17237#0: shmtx lock
2014/05/19 22:27:04 [debug] 17237#0: shmtx unlock
2014/05/19 22:27:04 [debug] 17237#0: *1 http upstream exit: 0000000000000000
2014/05/19 22:27:04 [debug] 17237#0: *1 finalize http upstream request: 0
2014/05/19 22:27:04 [debug] 17237#0: *1 finalize http ajp request
2014/05/19 22:27:04 [debug] 17237#0: *1 free rr peer 1 0
2014/05/19 22:27:04 [debug] 17237#0: *1 close http upstream connection: 12
2014/05/19 22:27:04 [debug] 17237#0: *1 free: 0000000001EA2A80, unused: 48
2014/05/19 22:27:04 [debug] 17237#0: *1 event timer del: 12: 1400563714154
2014/05/19 22:27:04 [debug] 17237#0: *1 reusable connection: 0
2014/05/19 22:27:04 [debug] 17237#0: *1 http upstream temp fd: 13
2014/05/19 22:27:04 [debug] 17237#0: *1 http output filter "/solr/admin/solr_small.png?"
2014/05/19 22:27:04 [debug] 17237#0: *1 http copy filter: "/solr/admin/solr_small.png?"
2014/05/19 22:27:04 [debug] 17237#0: *1 xslt filter body
2014/05/19 22:27:04 [debug] 17237#0: *1 http postpone filter "/solr/admin/solr_small.png?" 00007FFFD41598D0
2014/05/19 22:27:04 [debug] 17237#0: *1 write new buf t:0 f:0 0000000000000000, pos 0000000000000000, size: 0 file: 0, size: 0
2014/05/19 22:27:04 [debug] 17237#0: *1 http write filter: l:1 f:0 s:0
2014/05/19 22:27:04 [debug] 17237#0: *1 http copy filter: 0 "/solr/admin/solr_small.png?"
2014/05/19 22:27:04 [debug] 17237#0: *1 http finalize request: 0, "/solr/admin/solr_small.png?" a:1, c:1
2014/05/19 22:27:04 [debug] 17237#0: *1 set http keepalive handler
2014/05/19 22:27:04 [debug] 17237#0: *1 http close request
2014/05/19 22:27:04 [debug] 17237#0: *1 http log handler
2014/05/19 22:27:04 [debug] 17237#0: *1 run cleanup: 0000000001E96A30
2014/05/19 22:27:04 [debug] 17237#0: *1 file cleanup: fd:13
2014/05/19 22:27:04 [debug] 17237#0: *1 run cleanup: 0000000001E96278
2014/05/19 22:27:04 [debug] 17237#0: *1 free: 0000000001E90C60
2014/05/19 22:27:04 [debug] 17237#0: *1 free: 0000000001E8FC50
2014/05/19 22:27:04 [debug] 17237#0: *1 free: 0000000001E8DC40
2014/05/19 22:27:04 [debug] 17237#0: *1 free: 0000000001EA88A0, unused: 1
2014/05/19 22:27:04 [debug] 17237#0: *1 free: 0000000001E95AE0, unused: 0
2014/05/19 22:27:04 [debug] 17237#0: *1 free: 0000000001EE7ED0, unused: 3632
2014/05/19 22:27:04 [debug] 17237#0: *1 free: 0000000001EA3270
2014/05/19 22:27:04 [debug] 17237#0: *1 hc free: 0000000000000000 0
2014/05/19 22:27:04 [debug] 17237#0: *1 hc busy: 0000000000000000 0
2014/05/19 22:27:04 [debug] 17237#0: *1 tcp_nodelay
2014/05/19 22:27:04 [debug] 17237#0: *1 reusable connection: 1
2014/05/19 22:27:04 [debug] 17237#0: *1 event timer add: 11: 65000:1400563689156
2014/05/19 22:27:04 [debug] 17237#0: *1 post event 0000000001EB3F80
2014/05/19 22:27:04 [debug] 17237#0: timer delta: 2
2014/05/19 22:27:04 [debug] 17237#0: posted events 0000000001EB3F80
2014/05/19 22:27:04 [debug] 17237#0: posted event 0000000001EB3F80
2014/05/19 22:27:04 [debug] 17237#0: *1 delete posted event 0000000001EB3F80
2014/05/19 22:27:04 [debug] 17237#0: *1 http keepalive handler
2014/05/19 22:27:04 [debug] 17237#0: *1 malloc: 0000000001EA3270:1024
2014/05/19 22:27:04 [debug] 17237#0: *1 recv: fd:11 0 of 1024
2014/05/19 22:27:04 [info] 17237#0: *1 client 127.0.0.1 closed keepalive connection
2014/05/19 22:27:04 [debug] 17237#0: *1 close http connection: 11
2014/05/19 22:27:04 [debug] 17237#0: *1 event timer del: 11: 1400563689156
2014/05/19 22:27:04 [debug] 17237#0: *1 reusable connection: 0
2014/05/19 22:27:04 [debug] 17237#0: *1 free: 0000000001EA3270
2014/05/19 22:27:04 [debug] 17237#0: *1 free: 0000000001E89030, unused: 0
2014/05/19 22:27:04 [debug] 17237#0: *1 free: 0000000001E89190, unused: 120
2014/05/19 22:27:04 [debug] 17237#0: posted event 0000000000000000
2014/05/19 22:27:04 [debug] 17237#0: worker cycle
2014/05/19 22:27:04 [debug] 17237#0: epoll timer: -1
2014/05/19 22:27:07 [debug] 17237#0: epoll: fd:6 ev:0001 d:00007FAA59146010
2014/05/19 22:27:07 [debug] 17237#0: accept on 0.0.0.0:80, ready: 0
2014/05/19 22:27:07 [debug] 17237#0: posix_memalign: 0000000001E89030:256 @16
2014/05/19 22:27:07 [debug] 17237#0: *3 accept: 127.0.0.1 fd:11
2014/05/19 22:27:07 [debug] 17237#0: posix_memalign: 0000000001E89190:256 @16
2014/05/19 22:27:07 [debug] 17237#0: *3 event timer add: 11: 60000:1400563687224
2014/05/19 22:27:07 [debug] 17237#0: *3 reusable connection: 1
2014/05/19 22:27:07 [debug] 17237#0: *3 epoll add event: fd:11 op:1 ev:80002001
2014/05/19 22:27:07 [debug] 17237#0: timer delta: 3068
2014/05/19 22:27:07 [debug] 17237#0: posted events 0000000000000000
2014/05/19 22:27:07 [debug] 17237#0: worker cycle
2014/05/19 22:27:07 [debug] 17237#0: epoll timer: 60000
2014/05/19 22:27:07 [debug] 17237#0: epoll: fd:11 ev:0001 d:00007FAA591461C1
2014/05/19 22:27:07 [debug] 17237#0: *3 http wait request handler
2014/05/19 22:27:07 [debug] 17237#0: *3 malloc: 0000000001EA3270:1024
2014/05/19 22:27:07 [debug] 17237#0: *3 recv: fd:11 189 of 1024
2014/05/19 22:27:07 [debug] 17237#0: *3 reusable connection: 0
2014/05/19 22:27:07 [debug] 17237#0: *3 posix_memalign: 0000000001EA88A0:4096 @16
2014/05/19 22:27:07 [debug] 17237#0: *3 http process request line
2014/05/19 22:27:07 [debug] 17237#0: *3 http request line: "GET /solr/admin/solr_small.png HTTP/1.1"
2014/05/19 22:27:07 [debug] 17237#0: *3 http uri: "/solr/admin/solr_small.png"
2014/05/19 22:27:07 [debug] 17237#0: *3 http args: ""
2014/05/19 22:27:07 [debug] 17237#0: *3 http exten: "png"
2014/05/19 22:27:07 [debug] 17237#0: *3 http process request header line
2014/05/19 22:27:07 [debug] 17237#0: *3 http header: "User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.14.0.0 zlib/1.2.3 libidn/1.18 libssh2/1.4.2"
2014/05/19 22:27:07 [debug] 17237#0: *3 http header: "Host: localhost"
2014/05/19 22:27:07 [debug] 17237#0: *3 http header: "Accept: */*"
2014/05/19 22:27:07 [debug] 17237#0: *3 http header done
2014/05/19 22:27:07 [debug] 17237#0: *3 event timer del: 11: 1400563687224
2014/05/19 22:27:07 [debug] 17237#0: *3 generic phase: 0
2014/05/19 22:27:07 [debug] 17237#0: *3 rewrite phase: 1
2014/05/19 22:27:07 [debug] 17237#0: *3 test location: "/"
2014/05/19 22:27:07 [debug] 17237#0: *3 test location: ~ "^/.*\.(gif|jpg|png|js)$"
2014/05/19 22:27:07 [debug] 17237#0: *3 using configuration "^/.*\.(gif|jpg|png|js)$"
2014/05/19 22:27:07 [debug] 17237#0: *3 http cl:-1 max:1048576
2014/05/19 22:27:07 [debug] 17237#0: *3 rewrite phase: 3
2014/05/19 22:27:07 [debug] 17237#0: *3 post rewrite phase: 4
2014/05/19 22:27:07 [debug] 17237#0: *3 generic phase: 5
2014/05/19 22:27:07 [debug] 17237#0: *3 generic phase: 6
2014/05/19 22:27:07 [debug] 17237#0: *3 generic phase: 7
2014/05/19 22:27:07 [debug] 17237#0: *3 access phase: 8
2014/05/19 22:27:07 [debug] 17237#0: *3 access phase: 9
2014/05/19 22:27:07 [debug] 17237#0: *3 access phase: 10
2014/05/19 22:27:07 [debug] 17237#0: *3 access phase: 11
2014/05/19 22:27:07 [debug] 17237#0: *3 post access phase: 12
2014/05/19 22:27:07 [debug] 17237#0: *3 posix_memalign: 0000000001E95AE0:4096 @16
2014/05/19 22:27:07 [debug] 17237#0: *3 http init upstream, client timer: 0
2014/05/19 22:27:07 [debug] 17237#0: *3 epoll add event: fd:11 op:3 ev:80002005
2014/05/19 22:27:07 [debug] 17237#0: *3 http script var: "localhost"
2014/05/19 22:27:07 [debug] 17237#0: *3 http script var: "/solr/admin/solr_small.png"
2014/05/19 22:27:07 [debug] 17237#0: *3 http cache key: "localhost/solr/admin/solr_small.png"
2014/05/19 22:27:07 [debug] 17237#0: *3 add cleanup: 0000000001E96278
2014/05/19 22:27:07 [debug] 17237#0: shmtx lock
2014/05/19 22:27:07 [debug] 17237#0: shmtx unlock
2014/05/19 22:27:07 [debug] 17237#0: *3 http file cache exists: 0 e:1
2014/05/19 22:27:07 [debug] 17237#0: *3 cache file: "/var/cache/nginx/ajp_cache/f/66/d6d0ab0da12a1b0634bee1edbd0a466f"
2014/05/19 22:27:07 [debug] 17237#0: *3 add cleanup: 0000000001E962D8
2014/05/19 22:27:07 [debug] 17237#0: *3 http file cache fd: 12
2014/05/19 22:27:07 [debug] 17237#0: *3 read: 12, 0000000001E96358, 216, 0
2014/05/19 22:27:07 [debug] 17237#0: shmtx lock
2014/05/19 22:27:07 [debug] 17237#0: shmtx unlock
2014/05/19 22:27:07 [debug] 17237#0: *3 http upstream cache: 0
2014/05/19 22:27:07 [debug] 17237#0: *3 ngx_http_ajp_process_header: state(0)
2014/05/19 22:27:07 [debug] 17237#0: *3 ngx_http_ajp_process_header: parse response, pos:0000000001E963AA, last:0000000001E96430
2014/05/19 22:27:07 [debug] 17238#0: timer delta: 10011
2014/05/19 22:27:07 [debug] 17238#0: event timer del: -1: 1400563627361
2014/05/19 22:27:07 [debug] 17238#0: http file cache expire
2014/05/19 22:27:07 [debug] 17238#0: malloc: 0000000001EA2A80:65
2014/05/19 22:27:07 [debug] 17238#0: shmtx lock
2014/05/19 22:27:07 [debug] 17238#0: shmtx unlock
2014/05/19 22:27:07 [debug] 17238#0: shmtx lock
2014/05/19 22:27:07 [debug] 17238#0: shmtx unlock
2014/05/19 22:27:07 [debug] 17238#0: http file cache size: 2
2014/05/19 22:27:07 [debug] 17238#0: event timer add: -1: 10000:1400563637372
2014/05/19 22:27:07 [debug] 17238#0: posted events 0000000000000000
2014/05/19 22:27:07 [debug] 17238#0: epoll timer: 10000
2014/05/19 22:27:07 [notice] 17235#0: signal 17 (SIGCHLD) received
2014/05/19 22:27:07 [alert] 17235#0: worker process 17237 exited on signal 11 (core dumped)
2014/05/19 22:27:07 [debug] 17235#0: shmtx forced unlock
2014/05/19 22:27:07 [debug] 17235#0: shmtx forced unlock
2014/05/19 22:27:07 [debug] 17235#0: wake up, sigio 0
2014/05/19 22:27:07 [debug] 17235#0: reap children
2014/05/19 22:27:07 [debug] 17235#0: child: 0 17237 e:0 t:1 d:0 r:1 j:0
2014/05/19 22:27:07 [debug] 17235#0: pass close channel s:0 pid:17237 to:17238
2014/05/19 22:27:07 [debug] 17235#0: pass close channel s:0 pid:17237 to:17239
2014/05/19 22:27:07 [debug] 17235#0: channel 3:7
2014/05/19 22:27:07 [notice] 17235#0: start worker process 17244
2014/05/19 22:27:07 [debug] 17235#0: pass channel s:0 pid:17244 fd:3 to s:1 pid:17238 fd:8
2014/05/19 22:27:07 [debug] 17235#0: pass channel s:0 pid:17244 fd:3 to s:2 pid:17239 fd:10
2014/05/19 22:27:07 [debug] 17235#0: child: 1 17238 e:0 t:0 d:0 r:1 j:0
2014/05/19 22:27:07 [debug] 17235#0: child: 2 17239 e:0 t:0 d:0 r:0 j:0
2014/05/19 22:27:07 [debug] 17235#0: sigsuspend
2014/05/19 22:27:07 [debug] 17239#0: epoll: fd:11 ev:0001 d:0000000001EB3EB0
2014/05/19 22:27:07 [debug] 17239#0: channel handler
2014/05/19 22:27:07 [debug] 17239#0: channel: 32
2014/05/19 22:27:07 [debug] 17239#0: channel command: 2
2014/05/19 22:27:07 [debug] 17239#0: close channel s:0 pid:17237 our:17237 fd:3
2014/05/19 22:27:07 [debug] 17239#0: channel: 32
2014/05/19 22:27:07 [debug] 17239#0: channel command: 1
2014/05/19 22:27:07 [debug] 17239#0: get channel s:0 pid:17244 fd:3
2014/05/19 22:27:07 [debug] 17239#0: channel: -2
2014/05/19 22:27:07 [debug] 17239#0: timer delta: 10019
2014/05/19 22:27:07 [debug] 17239#0: posted events 0000000000000000
2014/05/19 22:27:07 [debug] 17239#0: epoll timer: 49981
2014/05/19 22:27:07 [debug] 17238#0: epoll: fd:9 ev:0001 d:0000000001EB3EB0
2014/05/19 22:27:07 [debug] 17238#0: channel handler
2014/05/19 22:27:07 [debug] 17238#0: channel: 32
2014/05/19 22:27:07 [debug] 17238#0: channel command: 2
2014/05/19 22:27:07 [debug] 17238#0: close channel s:0 pid:17237 our:17237 fd:3
2014/05/19 22:27:07 [debug] 17238#0: channel: 32
2014/05/19 22:27:07 [debug] 17238#0: channel command: 1
2014/05/19 22:27:07 [debug] 17238#0: get channel s:0 pid:17244 fd:3
2014/05/19 22:27:07 [debug] 17238#0: channel: -2
2014/05/19 22:27:07 [debug] 17238#0: timer delta: 2
2014/05/19 22:27:07 [debug] 17238#0: posted events 0000000000000000
2014/05/19 22:27:07 [debug] 17238#0: epoll timer: 9998
2014/05/19 22:27:07 [notice] 17235#0: signal 29 (SIGIO) received
2014/05/19 22:27:07 [debug] 17235#0: wake up, sigio 0
2014/05/19 22:27:07 [debug] 17235#0: sigsuspend
2014/05/19 22:27:07 [debug] 17244#0: eventfd: 13
2014/05/19 22:27:07 [debug] 17244#0: malloc: 0000000001E942D0:6144
2014/05/19 22:27:07 [debug] 17244#0: malloc: 00007FAA59146010:221184
2014/05/19 22:27:07 [debug] 17244#0: malloc: 0000000001EB3EB0:106496
2014/05/19 22:27:07 [debug] 17244#0: malloc: 0000000001ECDEC0:106496
2014/05/19 22:27:07 [debug] 17244#0: epoll add event: fd:6 op:1 ev:00002001
2014/05/19 22:27:07 [debug] 17244#0: epoll add event: fd:7 op:1 ev:00002001
2014/05/19 22:27:07 [debug] 17244#0: setproctitle: "nginx: worker process"
2014/05/19 22:27:07 [debug] 17244#0: worker cycle
2014/05/19 22:27:07 [debug] 17244#0: epoll timer: -1
2014/05/19 22:27:17 [debug] 17238#0: timer delta: 10009
2014/05/19 22:27:17 [debug] 17238#0: event timer del: -1: 1400563637372
2014/05/19 22:27:17 [debug] 17238#0: http file cache expire
2014/05/19 22:27:17 [debug] 17238#0: malloc: 0000000001EA2A80:65
2014/05/19 22:27:17 [debug] 17238#0: shmtx lock
2014/05/19 22:27:17 [debug] 17238#0: shmtx unlock
2014/05/19 22:27:17 [debug] 17238#0: shmtx lock
2014/05/19 22:27:17 [debug] 17238#0: shmtx unlock
2014/05/19 22:27:17 [debug] 17238#0: http file cache size: 2
2014/05/19 22:27:17 [debug] 17238#0: event timer add: -1: 10000:1400563647383
2014/05/19 22:27:17 [debug] 17238#0: posted events 0000000000000000
2014/05/19 22:27:17 [debug] 17238#0: epoll timer: 10000
2014/05/19 22:27:27 [debug] 17238#0: timer delta: 10011
2014/05/19 22:27:27 [debug] 17238#0: event timer del: -1: 1400563647383
2014/05/19 22:27:27 [debug] 17238#0: http file cache expire
2014/05/19 22:27:27 [debug] 17238#0: malloc: 0000000001EA2A80:65
2014/05/19 22:27:27 [debug] 17238#0: shmtx lock
2014/05/19 22:27:27 [debug] 17238#0: shmtx unlock
2014/05/19 22:27:27 [debug] 17238#0: shmtx lock
2014/05/19 22:27:27 [debug] 17238#0: shmtx unlock
2014/05/19 22:27:27 [debug] 17238#0: http file cache size: 2
2014/05/19 22:27:27 [debug] 17238#0: event timer add: -1: 10000:1400563657394
2014/05/19 22:27:27 [debug] 17238#0: posted events 0000000000000000
2014/05/19 22:27:27 [debug] 17238#0: epoll timer: 10000

[warn] ngx_http_upstream_send_request_body: bad state(3)，while reading response header from upstream

I have the same problem!!
NEED HELP!~~~~~~~~~

I experience the same bug :/