2014/06/25 18:36:07 [debug] 29435#0: *31 accept: 127.0.0.1:54178 fd:15 2014/06/25 18:36:07 [debug] 29435#0: *31 event timer add: 15: 60000:1403692627362 2014/06/25 18:36:07 [debug] 29435#0: *31 reusable connection: 1 2014/06/25 18:36:07 [debug] 29435#0: *31 epoll add event: fd:15 op:1 ev:80002001 2014/06/25 18:36:07 [debug] 29435#0: *31 http wait request handler 2014/06/25 18:36:07 [debug] 29435#0: *31 malloc: 00000000006FDF90:1024 2014/06/25 18:36:07 [debug] 29435#0: *31 recv: fd:15 175 of 1024 2014/06/25 18:36:07 [debug] 29435#0: *31 reusable connection: 0 2014/06/25 18:36:07 [debug] 29435#0: *31 posix_memalign: 00000000006FE3A0:4096 @16 2014/06/25 18:36:07 [debug] 29435#0: *31 http process request line 2014/06/25 18:36:07 [debug] 29435#0: *31 http request line: "GET /uri/a HTTP/1.1" 2014/06/25 18:36:07 [debug] 29435#0: *31 http uri: "/uri/a" 2014/06/25 18:36:07 [debug] 29435#0: *31 http args: "" 2014/06/25 18:36:07 [debug] 29435#0: *31 http exten: "" 2014/06/25 18:36:07 [debug] 29435#0: *31 http process request header line 2014/06/25 18:36:07 [debug] 29435#0: *31 http header: "User-Agent: curl/7.19.7 (x86_64-unknown-linux-gnu) libcurl/7.19.7 NSS/3.12.7.0 zlib/1.2.3 libidn/1.18 libssh2/1.2.2" 2014/06/25 18:36:07 [debug] 29435#0: *31 http header: "Host: 127.0.0.1:8080" 2014/06/25 18:36:07 [debug] 29435#0: *31 http header: "Accept: */*" 2014/06/25 18:36:07 [debug] 29435#0: *31 http header done 2014/06/25 18:36:07 [debug] 29435#0: *31 event timer del: 15: 1403692627362 2014/06/25 18:36:07 [debug] 29435#0: *31 rewrite phase: 0 2014/06/25 18:36:07 [debug] 29435#0: *31 test location: "/" 2014/06/25 18:36:07 [debug] 29435#0: *31 test location: "login" 2014/06/25 18:36:07 [debug] 29435#0: *31 test location: "test2" 2014/06/25 18:36:07 [debug] 29435#0: *31 using configuration "/" 2014/06/25 18:36:07 [debug] 29435#0: *31 http cl:-1 max:20971520 2014/06/25 18:36:07 [debug] 29435#0: *31 rewrite phase: 2 2014/06/25 18:36:07 [debug] 29435#0: *31 post rewrite phase: 3 2014/06/25 18:36:07 [debug] 29435#0: *31 generic phase: 4 2014/06/25 18:36:07 [debug] 29435#0: *31 generic phase: 5 2014/06/25 18:36:07 [debug] 29435#0: *31 access phase: 6 2014/06/25 18:36:07 [debug] 29435#0: *31 access phase: 7 2014/06/25 18:36:07 [debug] 29435#0: *31 post access phase: 8 2014/06/25 18:36:07 [debug] 29435#0: *31 posix_memalign: 00000000007223F0:4096 @16 2014/06/25 18:36:07 [debug] 29435#0: *31 http init upstream, client timer: 0 2014/06/25 18:36:07 [debug] 29435#0: *31 epoll add event: fd:15 op:3 ev:80002005 2014/06/25 18:36:07 [debug] 29435#0: *31 http script var: "/uri/a" 2014/06/25 18:36:07 [debug] 29435#0: *31 http cache key: "/uri/a" 2014/06/25 18:36:07 [debug] 29435#0: *31 add cleanup: 0000000000722B10 2014/06/25 18:36:07 [debug] 29435#0: *31 http file cache exists: -5 e:0 2014/06/25 18:36:07 [debug] 29435#0: *31 cache file: "/usr/local/nginx/cache/c0/4b/6e38e8dcfe0f57344b453eb30f974bc0" 2014/06/25 18:36:07 [debug] 29435#0: *31 add cleanup: 0000000000722B68 2014/06/25 18:36:07 [debug] 29435#0: *31 http file cache lock u:1 wt:0 2014/06/25 18:36:07 [debug] 29435#0: *31 http upstream cache: -5 2014/06/25 18:36:07 [debug] 29435#0: *31 http script copy: "User-Agent: 360 nginx src cache 2014/06/25 18:36:07 [debug] 29435#0: *31 http script copy: "X-Forwarded-For: " 2014/06/25 18:36:07 [debug] 29435#0: *31 http script var: "127.0.0.1" 2014/06/25 18:36:07 [debug] 29435#0: *31 http script copy: " 2014/06/25 18:36:07 [debug] 29435#0: *31 http script copy: "Host: " 2014/06/25 18:36:07 [debug] 29435#0: *31 http script var: "127.0.0.1" 2014/06/25 18:36:07 [debug] 29435#0: *31 http script copy: " 2014/06/25 18:36:07 [debug] 29435#0: *31 http script copy: "Connection: close 2014/06/25 18:36:07 [debug] 29435#0: *31 http script copy: "" 2014/06/25 18:36:07 [debug] 29435#0: *31 http script copy: "" 2014/06/25 18:36:07 [debug] 29435#0: *31 http script copy: "" 2014/06/25 18:36:07 [debug] 29435#0: *31 http script copy: "" 2014/06/25 18:36:07 [debug] 29435#0: *31 http proxy header: "Accept: */*" 2014/06/25 18:36:07 [debug] 29435#0: *31 http proxy header: 2014/06/25 18:36:07 [debug] 29435#0: *31 http cleanup add: 0000000000722D08 2014/06/25 18:36:07 [debug] 29435#0: *31 get rr peer, try: 1 2014/06/25 18:36:07 [debug] 29435#0: *31 socket 16 2014/06/25 18:36:07 [debug] 29435#0: *31 epoll add connection: fd:16 ev:80002005 2014/06/25 18:36:07 [debug] 29435#0: *31 connect to 127.0.0.1:8081, fd:16 #32 2014/06/25 18:36:07 [debug] 29435#0: *31 http upstream connect: -2 2014/06/25 18:36:07 [debug] 29435#0: *31 posix_memalign: 0000000000708A90:128 @16 2014/06/25 18:36:07 [debug] 29435#0: *31 event timer add: 16: 60000:1403692627362 2014/06/25 18:36:07 [debug] 29435#0: *31 http finalize request: -4, "/uri/a?" a:1, c:2 2014/06/25 18:36:07 [debug] 29435#0: *31 http request count:2 blk:0 2014/06/25 18:36:07 [debug] 29435#0: *31 http run request: "/uri/a?" 2014/06/25 18:36:07 [debug] 29435#0: *31 http upstream check client, write event:1, "/uri/a" 2014/06/25 18:36:07 [debug] 29435#0: *31 http upstream recv(): -1 (11: Resource temporarily unavailable) 2014/06/25 18:36:07 [debug] 29435#0: *31 http upstream request: "/uri/a?" 2014/06/25 18:36:07 [debug] 29435#0: *31 http upstream send request handler 2014/06/25 18:36:07 [debug] 29435#0: *31 http upstream send request 2014/06/25 18:36:07 [debug] 29435#0: *31 chain writer buf fl:1 s:133 2014/06/25 18:36:07 [debug] 29435#0: *31 chain writer in: 0000000000722D40 2014/06/25 18:36:07 [debug] 29435#0: *31 writev: 133 2014/06/25 18:36:07 [debug] 29435#0: *31 chain writer out: 0000000000000000 2014/06/25 18:36:07 [debug] 29435#0: *31 event timer del: 16: 1403692627362 2014/06/25 18:36:07 [debug] 29435#0: *31 event timer add: 16: 60000:1403692627363 2014/06/25 18:36:07 [debug] 29435#0: *31 http upstream request: "/uri/a?" 2014/06/25 18:36:07 [debug] 29435#0: *31 http upstream process header 2014/06/25 18:36:07 [debug] 29435#0: *31 malloc: 0000000000723400:4096 2014/06/25 18:36:07 [debug] 29435#0: *31 recv: fd:16 225 of 4043 2014/06/25 18:36:07 [debug] 29435#0: *31 http proxy status 200 "200 OK" 2014/06/25 18:36:07 [debug] 29435#0: *31 http proxy header: "Server: Tengine/1.5.1" 2014/06/25 18:36:07 [debug] 29435#0: *31 http proxy header: "Date: Wed, 25 Jun 2014 10:36:07 GMT" 2014/06/25 18:36:07 [debug] 29435#0: *31 http proxy header: "Content-Type: application/octet-stream" 2014/06/25 18:36:07 [debug] 29435#0: *31 http proxy header: "Content-Length: 2" 2014/06/25 18:36:07 [debug] 29435#0: *31 http proxy header: "Last-Modified: Fri, 14 Mar 2014 10:31:36 GMT" 2014/06/25 18:36:07 [debug] 29435#0: *31 http proxy header: "Connection: close" 2014/06/25 18:36:07 [debug] 29435#0: *31 http proxy header: "Accept-Ranges: bytes" 2014/06/25 18:36:07 [debug] 29435#0: *31 http proxy header done 2014/06/25 18:36:07 [debug] 29435#0: *31 http script var: "MISS" 2014/06/25 18:36:07 [debug] 29435#0: *31 HTTP/1.1 200 OK 2014/06/25 18:36:07 [debug] 29435#0: *31 write new buf t:1 f:0 0000000000723048, pos 0000000000723048, size: 238 file: 0, size: 0 2014/06/25 18:36:07 [debug] 29435#0: *31 http write filter: l:0 f:0 s:238 2014/06/25 18:36:07 [debug] 29435#0: *31 http proxy filter init s:200 h:0 c:0 l:2 2014/06/25 18:36:07 [debug] 29435#0: *31 tcp_nodelay 2014/06/25 18:36:07 [debug] 29435#0: *31 http output filter "/uri/a?" 2014/06/25 18:36:07 [debug] 29435#0: *31 http copy filter: "/uri/a?" 2014/06/25 18:36:07 [debug] 29435#0: *31 http postpone filter "/uri/a?" 00007FFFFFFFE200 2014/06/25 18:36:07 [debug] 29435#0: *31 write old buf t:1 f:0 0000000000723048, pos 0000000000723048, size: 238 file: 0, size: 0 2014/06/25 18:36:07 [debug] 29435#0: *31 write new buf t:0 f:0 0000000000000000, pos 0000000000000000, size: 0 file: 0, size: 0 2014/06/25 18:36:07 [debug] 29435#0: *31 http write filter: l:0 f:1 s:238 2014/06/25 18:36:07 [debug] 29435#0: *31 http write filter limit 8192 2014/06/25 18:36:07 [debug] 29435#0: *31 writev: 238 2014/06/25 18:36:07 [debug] 29435#0: *31 http write filter 0000000000000000 2014/06/25 18:36:07 [debug] 29435#0: *31 event timer add: 15: 1:1403692567364 2014/06/25 18:36:07 [debug] 29435#0: *31 http copy filter: 0 "/uri/a?" 2014/06/25 18:36:07 [debug] 29435#0: *31 http upstream process non buffered upstream 2014/06/25 18:36:07 [debug] 29435#0: *31 recv: fd:16 2 of 4096 2014/06/25 18:36:07 [debug] 29435#0: *31 http output filter "/uri/a?" 2014/06/25 18:36:07 [debug] 29435#0: *31 http copy filter: "/uri/a?" 2014/06/25 18:36:07 [debug] 29435#0: *31 http postpone filter "/uri/a?" 0000000000723218 2014/06/25 18:36:07 [debug] 29435#0: *31 write new buf t:0 f:0 0000000000000000, pos 0000000000723400, size: 2 file: 0, size: 0 2014/06/25 18:36:07 [debug] 29435#0: *31 http write filter: l:0 f:1 s:2 2014/06/25 18:36:07 [debug] 29435#0: *31 http copy filter: -2 "/uri/a?" 2014/06/25 18:36:07 [debug] 29435#0: *31 recv: fd:16 0 of 4094 2014/06/25 18:36:07 [debug] 29435#0: *31 http output filter "/uri/a?" 2014/06/25 18:36:07 [debug] 29435#0: *31 http copy filter: "/uri/a?" 2014/06/25 18:36:07 [debug] 29435#0: *31 http postpone filter "/uri/a?" 0000000000000000 2014/06/25 18:36:07 [debug] 29435#0: *31 write old buf t:0 f:0 0000000000000000, pos 0000000000723400, size: 2 file: 0, size: 0 2014/06/25 18:36:07 [debug] 29435#0: *31 http write filter: l:0 f:1 s:2 2014/06/25 18:36:07 [debug] 29435#0: *31 http copy filter: -2 "/uri/a?" 2014/06/25 18:36:07 [debug] 29435#0: *31 event timer del: 15: 1403692567364 2014/06/25 18:36:07 [debug] 29435#0: *31 event timer: 16, old: 1403692627363, new: 1403692627363 2014/06/25 18:36:07 [debug] 29435#0: *31 http upstream request: "/uri/a?" 2014/06/25 18:36:07 [debug] 29435#0: *31 http upstream dummy handler 2014/06/25 18:36:37 [debug] 29435#0: *31 http upstream request: "/uri/a?" 2014/06/25 18:36:37 [debug] 29435#0: *31 http upstream process non buffered upstream 2014/06/25 18:36:37 [debug] 29435#0: *31 http output filter "/uri/a?" 2014/06/25 18:36:37 [debug] 29435#0: *31 http copy filter: "/uri/a?" 2014/06/25 18:36:37 [debug] 29435#0: *31 http postpone filter "/uri/a?" 0000000000000000 2014/06/25 18:36:37 [debug] 29435#0: *31 write old buf t:0 f:0 0000000000000000, pos 0000000000723400, size: 2 file: 0, size: 0 2014/06/25 18:36:37 [debug] 29435#0: *31 http write filter: l:0 f:1 s:2 2014/06/25 18:36:37 [debug] 29435#0: *31 http copy filter: -2 "/uri/a?" 2014/06/25 18:36:37 [debug] 29435#0: *31 recv: fd:16 0 of 4094 2014/06/25 18:36:37 [debug] 29435#0: *31 http output filter "/uri/a?" 2014/06/25 18:36:37 [debug] 29435#0: *31 http copy filter: "/uri/a?" 2014/06/25 18:36:37 [debug] 29435#0: *31 http postpone filter "/uri/a?" 0000000000000000 2014/06/25 18:36:37 [debug] 29435#0: *31 write old buf t:0 f:0 0000000000000000, pos 0000000000723400, size: 2 file: 0, size: 0 2014/06/25 18:36:37 [debug] 29435#0: *31 http write filter: l:0 f:1 s:2 2014/06/25 18:36:37 [debug] 29435#0: *31 http copy filter: -2 "/uri/a?" 2014/06/25 18:36:37 [debug] 29435#0: *31 event timer del: 16: 1403692627363 2014/06/25 18:36:37 [debug] 29435#0: *31 event timer add: 16: 60000:1403692657639 2014/06/25 18:36:37 [debug] 29435#0: *31 http upstream request: "/uri/a?" 2014/06/25 18:36:37 [debug] 29435#0: *31 http upstream dummy handler