Skip to content

Instantly share code, notes, and snippets.

@harveyzh
Last active June 16, 2019 04:11
Show Gist options
  • Star 1 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save harveyzh/5055847 to your computer and use it in GitHub Desktop.
Save harveyzh/5055847 to your computer and use it in GitHub Desktop.
ngx.location.capture 指令直接调用 nginx-tfs 模块 block 时的 debug log,正常时的 debug log 和 nginx.conf 文件
2013/02/28 18:41:06 [debug] 29836#0: epoll: fd:6 ev:0001 d:00007FE52BECE010
2013/02/28 18:41:06 [debug] 29836#0: accept on 0.0.0.0:80, ready: 0
2013/02/28 18:41:06 [debug] 29836#0: posix_memalign: 0000000001BF4A20:256 @16
2013/02/28 18:41:06 [debug] 29836#0: *6 accept: 127.0.0.1 fd:3
2013/02/28 18:41:06 [debug] 29836#0: *6 event timer add: 3: 60000:1362048126878
2013/02/28 18:41:06 [debug] 29836#0: *6 epoll add event: fd:3 op:1 ev:80000001
2013/02/28 18:41:06 [debug] 29836#0: timer delta: 258361
2013/02/28 18:41:06 [debug] 29836#0: posted events 0000000000000000
2013/02/28 18:41:06 [debug] 29836#0: worker cycle
2013/02/28 18:41:06 [debug] 29836#0: epoll timer: 60000
2013/02/28 18:41:06 [debug] 29836#0: epoll: fd:3 ev:0001 d:00007FE52BECE311
2013/02/28 18:41:06 [debug] 29836#0: *6 malloc: 0000000001BFE020:1256
2013/02/28 18:41:06 [debug] 29836#0: *6 posix_memalign: 0000000001BF4CA0:256 @16
2013/02/28 18:41:06 [debug] 29836#0: *6 malloc: 0000000001C13FC0:1024
2013/02/28 18:41:06 [debug] 29836#0: *6 posix_memalign: 0000000001C143D0:4096 @16
2013/02/28 18:41:06 [debug] 29836#0: *6 http process request line
2013/02/28 18:41:06 [debug] 29836#0: *6 recv: fd:3 174 of 1024
2013/02/28 18:41:06 [debug] 29836#0: *6 http request line: "GET /test_block HTTP/1.1"
2013/02/28 18:41:06 [debug] 29836#0: *6 http uri: "/test_block"
2013/02/28 18:41:06 [debug] 29836#0: *6 http args: ""
2013/02/28 18:41:06 [debug] 29836#0: *6 http exten: ""
2013/02/28 18:41:06 [debug] 29836#0: *6 http process request header line
2013/02/28 18:41:06 [debug] 29836#0: *6 http header: "User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.13.1.0 zlib/1.2.3 libidn/1.18 libssh2/1.2.2"
2013/02/28 18:41:06 [debug] 29836#0: *6 http header: "Host: 127.0.0.1"
2013/02/28 18:41:06 [debug] 29836#0: *6 http header: "Accept: */*"
2013/02/28 18:41:06 [debug] 29836#0: *6 http header done
2013/02/28 18:41:06 [debug] 29836#0: *6 event timer del: 3: 1362048126878
2013/02/28 18:41:06 [debug] 29836#0: *6 rewrite phase: 0
2013/02/28 18:41:06 [debug] 29836#0: *6 rewrite phase: 1
2013/02/28 18:41:06 [debug] 29836#0: *6 test location: "/"
2013/02/28 18:41:06 [debug] 29836#0: *6 test location: "tfs/"
2013/02/28 18:41:06 [debug] 29836#0: *6 test location: "test_ok"
2013/02/28 18:41:06 [debug] 29836#0: *6 test location: "test_block"
2013/02/28 18:41:06 [debug] 29836#0: *6 using configuration "/test_block"
2013/02/28 18:41:06 [debug] 29836#0: *6 http cl:-1 max:1048576
2013/02/28 18:41:06 [debug] 29836#0: *6 rewrite phase: 3
2013/02/28 18:41:06 [debug] 29836#0: *6 rewrite phase: 4
2013/02/28 18:41:06 [debug] 29836#0: *6 post rewrite phase: 5
2013/02/28 18:41:06 [debug] 29836#0: *6 generic phase: 6
2013/02/28 18:41:06 [debug] 29836#0: *6 generic phase: 7
2013/02/28 18:41:06 [debug] 29836#0: *6 access phase: 8
2013/02/28 18:41:06 [debug] 29836#0: *6 access phase: 9
2013/02/28 18:41:06 [debug] 29836#0: *6 access phase: 10
2013/02/28 18:41:06 [debug] 29836#0: *6 access phase: 11
2013/02/28 18:41:06 [debug] 29836#0: *6 post access phase: 12
2013/02/28 18:41:06 [debug] 29836#0: *6 try files phase: 13
2013/02/28 18:41:06 [debug] 29836#0: *6 lua content handler, uri:"/test_block" c:1
2013/02/28 18:41:06 [debug] 29836#0: *6 lua reset ctx
2013/02/28 18:41:06 [debug] 29836#0: *6 lua creating new thread
2013/02/28 18:41:06 [debug] 29836#0: *6 http cleanup add: 0000000001C14FF0
2013/02/28 18:41:06 [debug] 29836#0: *6 lua run thread, top:0 c:1
2013/02/28 18:41:06 [debug] 29836#0: *6 lua location capture, uri:"/test_block" c:1
2013/02/28 18:41:06 [debug] 29836#0: *6 posix_memalign: 0000000001BF9750:4096 @16
2013/02/28 18:41:06 [debug] 29836#0: *6 http subrequest "/v1/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:41:06 [debug] 29836#0: *6 lua resume returned 1
2013/02/28 18:41:06 [debug] 29836#0: *6 lua thread yielded
2013/02/28 18:41:06 [debug] 29836#0: *6 http finalize request: -4, "/test_block?" a:1, c:3
2013/02/28 18:41:06 [debug] 29836#0: *6 http request count:3 blk:0
2013/02/28 18:41:06 [debug] 29836#0: *6 http posted request: "/v1/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:41:06 [debug] 29836#0: *6 rewrite phase: 0
2013/02/28 18:41:06 [debug] 29836#0: *6 rewrite phase: 1
2013/02/28 18:41:06 [debug] 29836#0: *6 test location: "/"
2013/02/28 18:41:06 [debug] 29836#0: *6 test location: "tfs/"
2013/02/28 18:41:06 [debug] 29836#0: *6 test location: "v1/tfs"
2013/02/28 18:41:06 [debug] 29836#0: *6 using configuration "/v1/tfs"
2013/02/28 18:41:06 [debug] 29836#0: *6 http cl:-1 max:1048576
2013/02/28 18:41:06 [debug] 29836#0: *6 rewrite phase: 3
2013/02/28 18:41:06 [debug] 29836#0: *6 rewrite phase: 4
2013/02/28 18:41:06 [debug] 29836#0: *6 post rewrite phase: 5
2013/02/28 18:41:06 [debug] 29836#0: *6 generic phase: 6
2013/02/28 18:41:06 [debug] 29836#0: *6 generic phase: 7
2013/02/28 18:41:06 [debug] 29836#0: *6 try files phase: 13
2013/02/28 18:41:06 [debug] 29836#0: *6 posix_memalign: 0000000001BFA760:4096 @16
2013/02/28 18:41:06 [debug] 29836#0: *6 http init tfs, client timer: 0
2013/02/28 18:41:06 [debug] 29836#0: *6 epoll add event: fd:3 op:3 ev:80000005
2013/02/28 18:41:06 [info] 29836#0: *6 meta segment: block_id: 2262, fileid: 1, seq_id: 1, suffix: 0, client: 127.0.0.1, server: 127.0.0.1,, request: "GET /test_block HTTP/1.1", subrequest: "/v1/tfs/T17yCTByJT1RCvBVdK", host: "127.0.0.1"
2013/02/28 18:41:06 [info] 29836#0: *6 get block info from ns while connecting server, client: 127.0.0.1, server: 127.0.0.1,, request: "GET /test_block HTTP/1.1", subrequest: "/v1/tfs/T17yCTByJT1RCvBVdK", host: "127.0.0.1"
2013/02/28 18:41:06 [debug] 29836#0: *6 connecting name server, addr: 10.80.102.105:8108
2013/02/28 18:41:06 [debug] 29836#0: *6 get keepalive peer
2013/02/28 18:41:06 [debug] 29836#0: *6 get keepalive peer: using connection 00007FE52BECE3D0
2013/02/28 18:41:06 [debug] 29836#0: *6 http tfs send request to name server, addr: 10.80.102.105:8108
2013/02/28 18:41:06 [debug] 29836#0: *6 chain writer buf fl:0 s:36
2013/02/28 18:41:06 [debug] 29836#0: *6 chain writer in: 0000000001C153B8
2013/02/28 18:41:06 [debug] 29836#0: *6 writev: 36
2013/02/28 18:41:06 [debug] 29836#0: *6 chain writer out: 0000000000000000
2013/02/28 18:41:06 [debug] 29836#0: *6 event timer add: 11: 3000:1362048069878
2013/02/28 18:41:06 [debug] 29836#0: *6 http tfs process tfs(name server) data
2013/02/28 18:41:06 [debug] 29836#0: *6 http tfs process request body for name server, addr: 10.80.102.105:8108
2013/02/28 18:41:06 [debug] 29836#0: *6 malloc: 0000000001CEA740:2097152
2013/02/28 18:41:06 [debug] 29836#0: *6 event timer del: 11: 1362048069878
2013/02/28 18:41:06 [debug] 29836#0: *6 readv: 2:2097152
2013/02/28 18:41:06 [debug] 29836#0: *6 readv() not ready (11: Resource temporarily unavailable)
2013/02/28 18:41:06 [debug] 29836#0: *6 event timer add: 11: 3000:1362048069878
2013/02/28 18:41:06 [debug] 29836#0: *6 http finalize request: -4, "/v1/tfs/T17yCTByJT1RCvBVdK?" a:0, c:3
2013/02/28 18:41:06 [debug] 29836#0: *6 http request count:3 blk:0
2013/02/28 18:41:06 [debug] 29836#0: timer delta: 0
2013/02/28 18:41:06 [debug] 29836#0: posted events 0000000000000000
2013/02/28 18:41:06 [debug] 29836#0: worker cycle
2013/02/28 18:41:06 [debug] 29836#0: epoll timer: 3000
2013/02/28 18:41:06 [debug] 29836#0: epoll: fd:3 ev:0004 d:00007FE52BECE311
2013/02/28 18:41:06 [debug] 29836#0: *6 http run request: "/test_block?"
2013/02/28 18:41:06 [debug] 29836#0: *6 http request empty handler
2013/02/28 18:41:06 [debug] 29836#0: epoll: fd:11 ev:0005 d:00007FE52BECE3D0
2013/02/28 18:41:06 [debug] 29836#0: *6 http tfs request: "/v1/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:41:06 [debug] 29836#0: *6 http tfs process tfs(name server) data
2013/02/28 18:41:06 [debug] 29836#0: *6 http tfs process request body for name server, addr: 10.80.102.105:8108
2013/02/28 18:41:06 [debug] 29836#0: *6 event timer del: 11: 1362048069878
2013/02/28 18:41:06 [debug] 29836#0: *6 readv: 2:2097152
2013/02/28 18:41:06 [debug] 29836#0: *6 insert local block cache, ns addr: 34825363148810, block id: 2262
2013/02/28 18:41:06 [debug] 29836#0: shmtx lock
2013/02/28 18:41:06 [debug] 29836#0: slab alloc: 88 slot: 4
2013/02/28 18:41:06 [debug] 29836#0: slab alloc: 00007FE52CC4D100
2013/02/28 18:41:06 [debug] 29836#0: shmtx unlock
2013/02/28 18:41:06 [debug] 29836#0: *6 get block info from nameserver: , block id: 2262, ds count: 2, version: 0, lease id: 0
2013/02/28 18:41:06 [debug] 29836#0: *6 select data server, ds_retry: 0, ds_index: 1
2013/02/28 18:41:06 [info] 29836#0: *6 http tfs finalize state name server, 0 while reading response header from tfs, client: 127.0.0.1, server: 127.0.0.1,, request: "GET /test_block HTTP/1.1", subrequest: "/v1/tfs/T17yCTByJT1RCvBVdK", host: "127.0.0.1"
2013/02/28 18:41:06 [debug] 29836#0: *6 free keepalive peer
2013/02/28 18:41:06 [debug] 29836#0: *6 free keepalive peer: saving connection 00007FE52BECE3D0
2013/02/28 18:41:06 [debug] 29836#0: keepalive close handler
2013/02/28 18:41:06 [info] 29836#0: *6 http tfs process next peer is data server, addr: 10.80.102.101:9998 while reading response header from tfs, client: 127.0.0.1, server: 127.0.0.1,, request: "GET /test_block HTTP/1.1", subrequest: "/v1/tfs/T17yCTByJT1RCvBVdK", host: "127.0.0.1"
2013/02/28 18:41:06 [info] 29836#0: *6 read segment index 0, block id: 2262, file id: 1, offset: 0, length: 524288 while connecting server, client: 127.0.0.1, server: 127.0.0.1,, request: "GET /test_block HTTP/1.1", subrequest: "/v1/tfs/T17yCTByJT1RCvBVdK", host: "127.0.0.1"
2013/02/28 18:41:06 [debug] 29836#0: *6 connecting data server, addr: 10.80.102.101:9998
2013/02/28 18:41:06 [debug] 29836#0: *6 get keepalive peer
2013/02/28 18:41:06 [debug] 29836#0: *6 socket 9
2013/02/28 18:41:06 [debug] 29836#0: *6 epoll add connection: fd:9 ev:80000005
2013/02/28 18:41:06 [debug] 29836#0: *6 connect to data server, fd:9 #7
2013/02/28 18:41:06 [debug] 29836#0: *6 posix_memalign: 0000000001C22360:128 @16
2013/02/28 18:41:06 [debug] 29836#0: *6 event timer add: 9: 3000:1362048069879
2013/02/28 18:41:06 [debug] 29836#0: keepalive dummy handler
2013/02/28 18:41:06 [debug] 29836#0: timer delta: 1
2013/02/28 18:41:06 [debug] 29836#0: posted events 0000000000000000
2013/02/28 18:41:06 [debug] 29836#0: worker cycle
2013/02/28 18:41:06 [debug] 29836#0: epoll timer: 3000
2013/02/28 18:41:06 [debug] 29836#0: epoll: fd:9 ev:0004 d:00007FE52BECE191
2013/02/28 18:41:06 [debug] 29836#0: *6 http tfs request: "/v1/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:41:06 [debug] 29836#0: *6 http tfs send request
2013/02/28 18:41:06 [debug] 29836#0: *6 http tfs send request to data server, addr: 10.80.102.101:9998
2013/02/28 18:41:06 [debug] 29836#0: *6 chain writer buf fl:0 s:45
2013/02/28 18:41:06 [debug] 29836#0: *6 chain writer in: 0000000001BFA720
2013/02/28 18:41:06 [debug] 29836#0: *6 writev: 45
2013/02/28 18:41:06 [debug] 29836#0: *6 chain writer out: 0000000000000000
2013/02/28 18:41:06 [debug] 29836#0: *6 event timer del: 9: 1362048069879
2013/02/28 18:41:06 [debug] 29836#0: *6 event timer add: 9: 3000:1362048069879
2013/02/28 18:41:06 [debug] 29836#0: timer delta: 0
2013/02/28 18:41:06 [debug] 29836#0: posted events 0000000000000000
2013/02/28 18:41:06 [debug] 29836#0: worker cycle
2013/02/28 18:41:06 [debug] 29836#0: epoll timer: 3000
2013/02/28 18:41:06 [debug] 29836#0: epoll: fd:9 ev:0005 d:00007FE52BECE191
2013/02/28 18:41:06 [debug] 29836#0: *6 http tfs request: "/v1/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:41:06 [debug] 29836#0: *6 http tfs process tfs(data server) data
2013/02/28 18:41:06 [debug] 29836#0: *6 http tfs process request body for data server, addr: 10.80.102.101:9998
2013/02/28 18:41:06 [debug] 29836#0: *6 malloc: 0000000001EEA750:2097152
2013/02/28 18:41:06 [debug] 29836#0: *6 event timer del: 9: 1362048069879
2013/02/28 18:41:06 [debug] 29836#0: *6 readv: 2:2097152
2013/02/28 18:41:06 [debug] 29836#0: *6 read len is 135, data len is 95
2013/02/28 18:41:06 [debug] 29836#0: *6 t->length is 0, rc is 0
2013/02/28 18:41:06 [info] 29836#0: *6 http tfs finalize state data server, -4 while reading response header from tfs, client: 127.0.0.1, server: 127.0.0.1,, request: "GET /test_block HTTP/1.1", subrequest: "/v1/tfs/T17yCTByJT1RCvBVdK", host: "127.0.0.1"
2013/02/28 18:41:06 [info] 29836#0: *6 read_file success while reading response header from tfs, client: 127.0.0.1, server: 127.0.0.1,, request: "GET /test_block HTTP/1.1", subrequest: "/v1/tfs/T17yCTByJT1RCvBVdK", host: "127.0.0.1"
2013/02/28 18:41:06 [debug] 29836#0: *6 lua capture header filter, uri "/v1/tfs/T17yCTByJT1RCvBVdK"
2013/02/28 18:41:06 [debug] 29836#0: *6 lua capturing response body
2013/02/28 18:41:06 [debug] 29836#0: *6 tcp_nodelay
2013/02/28 18:41:06 [debug] 29836#0: *6 http tfs upstream process downstream
2013/02/28 18:41:06 [debug] 29836#0: *6 http output filter "/v1/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:41:06 [debug] 29836#0: *6 http copy filter: "/v1/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:41:06 [debug] 29836#0: *6 lua capture body filter, uri "/v1/tfs/T17yCTByJT1RCvBVdK"
2013/02/28 18:41:06 [debug] 29836#0: *6 lua capture body filter capturing response body, uri "/v1/tfs/T17yCTByJT1RCvBVdK"
2013/02/28 18:41:06 [debug] 29836#0: *6 lua allocate new chainlink and new buf of size 95, cl:0000000001BFB688
2013/02/28 18:41:06 [debug] 29836#0: *6 http copy filter: 0 "/v1/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:41:06 [info] 29836#0: *6 read_file , output 2097152 byte while sending to client, client: 127.0.0.1, server: 127.0.0.1,, request: "GET /test_block HTTP/1.1", subrequest: "/v1/tfs/T17yCTByJT1RCvBVdK", host: "127.0.0.1"
2013/02/28 18:41:06 [debug] 29836#0: *6 finalize http tfs request: 0
2013/02/28 18:41:06 [debug] 29836#0: *6 free keepalive peer
2013/02/28 18:41:06 [debug] 29836#0: *6 free keepalive peer
2013/02/28 18:41:06 [debug] 29836#0: *6 free keepalive peer: saving connection 00007FE52BECE190
2013/02/28 18:41:06 [debug] 29836#0: keepalive close handler
2013/02/28 18:41:06 [debug] 29836#0: *6 <== conn pool check ==> all keepalive peers are free
2013/02/28 18:41:06 [debug] 29836#0: *6 posix_memalign: 0000000001BFB770:4096 @16
2013/02/28 18:41:06 [debug] 29836#0: *6 http output filter "/v1/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:41:06 [debug] 29836#0: *6 http copy filter: "/v1/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:41:06 [debug] 29836#0: *6 lua capture body filter, uri "/v1/tfs/T17yCTByJT1RCvBVdK"
2013/02/28 18:41:06 [debug] 29836#0: *6 lua capture body filter capturing response body, uri "/v1/tfs/T17yCTByJT1RCvBVdK"
2013/02/28 18:41:06 [debug] 29836#0: *6 http copy filter: 0 "/v1/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:41:06 [debug] 29836#0: *6 http finalize request: 0, "/v1/tfs/T17yCTByJT1RCvBVdK?" a:0, c:2
2013/02/28 18:41:06 [debug] 29836#0: *6 lua run post subrequest handler, rc:0 c:2
2013/02/28 18:41:06 [debug] 29836#0: *6 lua restoring write event handler
2013/02/28 18:41:06 [debug] 29836#0: *6 http wake parent request: "/test_block?"
2013/02/28 18:41:06 [debug] 29836#0: keepalive dummy handler
2013/02/28 18:41:06 [debug] 29836#0: timer delta: 1
2013/02/28 18:41:06 [debug] 29836#0: posted events 0000000000000000
2013/02/28 18:41:06 [debug] 29836#0: worker cycle
2013/02/28 18:41:06 [debug] 29836#0: epoll timer: -1
2013/02/28 18:41:47 [debug] 29836#0: epoll: fd:3 ev:0005 d:00007FE52BECE311
2013/02/28 18:41:47 [debug] 29836#0: *6 http run request: "/test_block?"
2013/02/28 18:41:47 [debug] 29836#0: *6 http reading blocked
2013/02/28 18:41:47 [debug] 29836#0: *6 http posted request: "/test_block?"
2013/02/28 18:41:47 [debug] 29836#0: *6 lua run subrequests done, resuming lua thread
2013/02/28 18:41:47 [debug] 29836#0: *6 lua handle subrequest responses
2013/02/28 18:41:47 [debug] 29836#0: *6 lua run thread, top:0 c:1
2013/02/28 18:41:47 [debug] 29836#0: *6 lua reuse free buf memory 95 >= 95, cl:0000000001BFB688, p:0000000001BFB6E8
2013/02/28 18:41:47 [debug] 29836#0: *6 lua print response
2013/02/28 18:41:47 [debug] 29836#0: *6 lua capture header filter, uri "/test_block"
2013/02/28 18:41:47 [debug] 29836#0: *6 HTTP/1.1 200 OK
Server: ngx_openresty
Date: Thu, 28 Feb 2013 10:41:47 GMT
Content-Type: application/octet-stream
Transfer-Encoding: chunked
Connection: keep-alive
2013/02/28 18:41:47 [debug] 29836#0: *6 write new buf t:1 f:0 0000000001BFB8B0, pos 0000000001BFB8B0, size: 171 file: 0, size: 0
2013/02/28 18:41:47 [debug] 29836#0: *6 http write filter: l:0 f:0 s:171
2013/02/28 18:41:47 [debug] 29836#0: *6 http output filter "/test_block?"
2013/02/28 18:41:47 [debug] 29836#0: *6 http copy filter: "/test_block?"
2013/02/28 18:41:47 [debug] 29836#0: *6 lua capture body filter, uri "/test_block"
2013/02/28 18:41:47 [debug] 29836#0: *6 http postpone filter "/test_block?" 0000000001BFB688
2013/02/28 18:41:47 [debug] 29836#0: *6 http chunk: 95
2013/02/28 18:41:47 [debug] 29836#0: *6 write old buf t:1 f:0 0000000001BFB8B0, pos 0000000001BFB8B0, size: 171 file: 0, size: 0
2013/02/28 18:41:47 [debug] 29836#0: *6 write new buf t:1 f:0 0000000001BFBA48, pos 0000000001BFBA48, size: 4 file: 0, size: 0
2013/02/28 18:41:47 [debug] 29836#0: *6 write new buf t:1 f:0 0000000001BFB6E8, pos 0000000001BFB6E8, size: 95 file: 0, size: 0
2013/02/28 18:41:47 [debug] 29836#0: *6 write new buf t:0 f:0 0000000000000000, pos 0000000000569C28, size: 2 file: 0, size: 0
2013/02/28 18:41:47 [debug] 29836#0: *6 http write filter: l:0 f:0 s:272
2013/02/28 18:41:47 [debug] 29836#0: *6 http copy filter: 0 "/test_block?"
2013/02/28 18:41:47 [debug] 29836#0: *6 lua resume returned 0
2013/02/28 18:41:47 [debug] 29836#0: *6 lua light thread ended normally
2013/02/28 18:41:47 [debug] 29836#0: *6 lua deleting light thread
2013/02/28 18:41:47 [debug] 29836#0: *6 lua sending last buf of the response body
2013/02/28 18:41:47 [debug] 29836#0: *6 http output filter "/test_block?"
2013/02/28 18:41:47 [debug] 29836#0: *6 http copy filter: "/test_block?"
2013/02/28 18:41:47 [debug] 29836#0: *6 lua capture body filter, uri "/test_block"
2013/02/28 18:41:47 [debug] 29836#0: *6 http postpone filter "/test_block?" 00007FFF069CDD30
2013/02/28 18:41:47 [debug] 29836#0: *6 http chunk: 0
2013/02/28 18:41:47 [debug] 29836#0: *6 write old buf t:1 f:0 0000000001BFB8B0, pos 0000000001BFB8B0, size: 171 file: 0, size: 0
2013/02/28 18:41:47 [debug] 29836#0: *6 write old buf t:1 f:0 0000000001BFBA48, pos 0000000001BFBA48, size: 4 file: 0, size: 0
2013/02/28 18:41:47 [debug] 29836#0: *6 write old buf t:1 f:0 0000000001BFB6E8, pos 0000000001BFB6E8, size: 95 file: 0, size: 0
2013/02/28 18:41:47 [debug] 29836#0: *6 write old buf t:0 f:0 0000000000000000, pos 0000000000569C28, size: 2 file: 0, size: 0
2013/02/28 18:41:47 [debug] 29836#0: *6 write new buf t:0 f:0 0000000000000000, pos 0000000000569C22, size: 5 file: 0, size: 0
2013/02/28 18:41:47 [debug] 29836#0: *6 http write filter: l:1 f:0 s:277
2013/02/28 18:41:47 [debug] 29836#0: *6 http write filter limit 0
2013/02/28 18:41:47 [debug] 29836#0: *6 writev: 277
2013/02/28 18:41:47 [debug] 29836#0: *6 http write filter 0000000000000000
2013/02/28 18:41:47 [debug] 29836#0: *6 http copy filter: 0 "/test_block?"
2013/02/28 18:41:47 [debug] 29836#0: *6 lua run thread returned 0
2013/02/28 18:41:47 [debug] 29836#0: *6 http finalize request: 0, "/test_block?" a:1, c:1
2013/02/28 18:41:47 [debug] 29836#0: *6 set http keepalive handler
2013/02/28 18:41:47 [debug] 29836#0: *6 http close request
2013/02/28 18:41:47 [debug] 29836#0: *6 lua request cleanup
2013/02/28 18:41:47 [debug] 29836#0: *6 http log handler
2013/02/28 18:41:47 [debug] 29836#0: *6 free: 0000000001EEA750
2013/02/28 18:41:47 [debug] 29836#0: *6 free: 0000000001CEA740
2013/02/28 18:41:47 [debug] 29836#0: *6 free: 0000000001C143D0, unused: 8
2013/02/28 18:41:47 [debug] 29836#0: *6 free: 0000000001BF9750, unused: 0
2013/02/28 18:41:47 [debug] 29836#0: *6 free: 0000000001BFA760, unused: 8
2013/02/28 18:41:47 [debug] 29836#0: *6 free: 0000000001BFB770, unused: 2756
2013/02/28 18:41:47 [debug] 29836#0: *6 event timer add: 3: 65000:1362048172906
2013/02/28 18:41:47 [debug] 29836#0: *6 free: 0000000001BFE020
2013/02/28 18:41:47 [debug] 29836#0: *6 free: 0000000001C13FC0
2013/02/28 18:41:47 [debug] 29836#0: *6 hc free: 0000000000000000 0
2013/02/28 18:41:47 [debug] 29836#0: *6 hc busy: 0000000000000000 0
2013/02/28 18:41:47 [debug] 29836#0: *6 reusable connection: 1
2013/02/28 18:41:47 [debug] 29836#0: *6 post event 00007FE52B84D1B0
2013/02/28 18:41:47 [debug] 29836#0: *6 http empty handler
2013/02/28 18:41:47 [debug] 29836#0: timer delta: 41026
2013/02/28 18:41:47 [debug] 29836#0: posted events 00007FE52B84D1B0
2013/02/28 18:41:47 [debug] 29836#0: posted event 00007FE52B84D1B0
2013/02/28 18:41:47 [debug] 29836#0: *6 delete posted event 00007FE52B84D1B0
2013/02/28 18:41:47 [debug] 29836#0: *6 http keepalive handler
2013/02/28 18:41:47 [debug] 29836#0: *6 malloc: 0000000001BFE020:1024
2013/02/28 18:41:47 [debug] 29836#0: *6 recv: fd:3 0 of 1024
2013/02/28 18:41:47 [info] 29836#0: *6 client 127.0.0.1 closed keepalive connection
2013/02/28 18:41:47 [debug] 29836#0: *6 close http connection: 3
2013/02/28 18:41:47 [debug] 29836#0: *6 event timer del: 3: 1362048172906
2013/02/28 18:41:47 [debug] 29836#0: *6 reusable connection: 0
2013/02/28 18:41:47 [debug] 29836#0: *6 free: 0000000001BFE020
2013/02/28 18:41:47 [debug] 29836#0: *6 free: 0000000000000000
2013/02/28 18:41:47 [debug] 29836#0: *6 free: 0000000001BF4A20, unused: 8
2013/02/28 18:41:47 [debug] 29836#0: *6 free: 0000000001BF4CA0, unused: 128
2013/02/28 18:41:47 [debug] 29836#0: posted event 0000000000000000
2013/02/28 18:41:47 [debug] 29836#0: worker cycle
2013/02/28 18:41:47 [debug] 29836#0: epoll timer: -1
2013/02/28 18:36:48 [debug] 29836#0: epoll: fd:6 ev:0001 d:00007FE52BECE010
2013/02/28 18:36:48 [debug] 29836#0: accept on 0.0.0.0:80, ready: 0
2013/02/28 18:36:48 [debug] 29836#0: posix_memalign: 0000000001BF4A20:256 @16
2013/02/28 18:36:48 [debug] 29836#0: *1 accept: 127.0.0.1 fd:3
2013/02/28 18:36:48 [debug] 29836#0: *1 event timer add: 3: 60000:1362047868512
2013/02/28 18:36:48 [debug] 29836#0: *1 epoll add event: fd:3 op:1 ev:80000001
2013/02/28 18:36:48 [debug] 29836#0: timer delta: 36979
2013/02/28 18:36:48 [debug] 29836#0: posted events 0000000000000000
2013/02/28 18:36:48 [debug] 29836#0: worker cycle
2013/02/28 18:36:48 [debug] 29836#0: epoll timer: 60000
2013/02/28 18:36:48 [debug] 29836#0: epoll: fd:3 ev:0001 d:00007FE52BECE190
2013/02/28 18:36:48 [debug] 29836#0: *1 malloc: 0000000001BFE020:1256
2013/02/28 18:36:48 [debug] 29836#0: *1 posix_memalign: 0000000001BFE510:256 @16
2013/02/28 18:36:48 [debug] 29836#0: *1 malloc: 0000000001C13FC0:1024
2013/02/28 18:36:48 [debug] 29836#0: *1 posix_memalign: 0000000001C143D0:4096 @16
2013/02/28 18:36:48 [debug] 29836#0: *1 http process request line
2013/02/28 18:36:48 [debug] 29836#0: *1 recv: fd:3 171 of 1024
2013/02/28 18:36:48 [debug] 29836#0: *1 http request line: "GET /test_ok HTTP/1.1"
2013/02/28 18:36:48 [debug] 29836#0: *1 http uri: "/test_ok"
2013/02/28 18:36:48 [debug] 29836#0: *1 http args: ""
2013/02/28 18:36:48 [debug] 29836#0: *1 http exten: ""
2013/02/28 18:36:48 [debug] 29836#0: *1 http process request header line
2013/02/28 18:36:48 [debug] 29836#0: *1 http header: "User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.13.1.0 zlib/1.2.3 libidn/1.18 libssh2/1.2.2"
2013/02/28 18:36:48 [debug] 29836#0: *1 http header: "Host: 127.0.0.1"
2013/02/28 18:36:48 [debug] 29836#0: *1 http header: "Accept: */*"
2013/02/28 18:36:48 [debug] 29836#0: *1 http header done
2013/02/28 18:36:48 [debug] 29836#0: *1 event timer del: 3: 1362047868512
2013/02/28 18:36:48 [debug] 29836#0: *1 rewrite phase: 0
2013/02/28 18:36:48 [debug] 29836#0: *1 rewrite phase: 1
2013/02/28 18:36:48 [debug] 29836#0: *1 test location: "/"
2013/02/28 18:36:48 [debug] 29836#0: *1 test location: "tfs/"
2013/02/28 18:36:48 [debug] 29836#0: *1 test location: "test_ok"
2013/02/28 18:36:48 [debug] 29836#0: *1 using configuration "/test_ok"
2013/02/28 18:36:48 [debug] 29836#0: *1 http cl:-1 max:1048576
2013/02/28 18:36:48 [debug] 29836#0: *1 rewrite phase: 3
2013/02/28 18:36:48 [debug] 29836#0: *1 rewrite phase: 4
2013/02/28 18:36:48 [debug] 29836#0: *1 post rewrite phase: 5
2013/02/28 18:36:48 [debug] 29836#0: *1 generic phase: 6
2013/02/28 18:36:48 [debug] 29836#0: *1 generic phase: 7
2013/02/28 18:36:48 [debug] 29836#0: *1 access phase: 8
2013/02/28 18:36:48 [debug] 29836#0: *1 access phase: 9
2013/02/28 18:36:48 [debug] 29836#0: *1 access phase: 10
2013/02/28 18:36:48 [debug] 29836#0: *1 access phase: 11
2013/02/28 18:36:48 [debug] 29836#0: *1 post access phase: 12
2013/02/28 18:36:48 [debug] 29836#0: *1 try files phase: 13
2013/02/28 18:36:48 [debug] 29836#0: *1 lua content handler, uri:"/test_ok" c:1
2013/02/28 18:36:48 [debug] 29836#0: *1 lua reset ctx
2013/02/28 18:36:48 [debug] 29836#0: *1 lua creating new thread
2013/02/28 18:36:48 [debug] 29836#0: *1 http cleanup add: 0000000001C14FF0
2013/02/28 18:36:48 [debug] 29836#0: *1 lua run thread, top:0 c:1
2013/02/28 18:36:48 [debug] 29836#0: *1 lua location capture, uri:"/test_ok" c:1
2013/02/28 18:36:48 [debug] 29836#0: *1 posix_memalign: 0000000001BF9750:4096 @16
2013/02/28 18:36:48 [debug] 29836#0: *1 http subrequest "/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:36:48 [debug] 29836#0: *1 lua resume returned 1
2013/02/28 18:36:48 [debug] 29836#0: *1 lua thread yielded
2013/02/28 18:36:48 [debug] 29836#0: *1 http finalize request: -4, "/test_ok?" a:1, c:3
2013/02/28 18:36:48 [debug] 29836#0: *1 http request count:3 blk:0
2013/02/28 18:36:48 [debug] 29836#0: *1 http posted request: "/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:36:48 [debug] 29836#0: *1 rewrite phase: 0
2013/02/28 18:36:48 [debug] 29836#0: *1 rewrite phase: 1
2013/02/28 18:36:48 [debug] 29836#0: *1 test location: "/"
2013/02/28 18:36:48 [debug] 29836#0: *1 test location: "tfs/"
2013/02/28 18:36:48 [debug] 29836#0: *1 using configuration "/tfs/"
2013/02/28 18:36:48 [debug] 29836#0: *1 http cl:-1 max:1048576
2013/02/28 18:36:48 [debug] 29836#0: *1 rewrite phase: 3
2013/02/28 18:36:48 [debug] 29836#0: *1 rewrite phase: 4
2013/02/28 18:36:48 [debug] 29836#0: *1 post rewrite phase: 5
2013/02/28 18:36:48 [debug] 29836#0: *1 generic phase: 6
2013/02/28 18:36:48 [debug] 29836#0: *1 generic phase: 7
2013/02/28 18:36:48 [debug] 29836#0: *1 try files phase: 13
2013/02/28 18:36:48 [debug] 29836#0: *1 http init upstream, client timer: 0
2013/02/28 18:36:48 [debug] 29836#0: *1 epoll add event: fd:3 op:3 ev:80000005
2013/02/28 18:36:48 [debug] 29836#0: *1 http script copy: "Host: "
2013/02/28 18:36:48 [debug] 29836#0: *1 http script var: "127.0.0.1"
2013/02/28 18:36:48 [debug] 29836#0: *1 http script copy: "
"
2013/02/28 18:36:48 [debug] 29836#0: *1 http script copy: "Connection: close
"
2013/02/28 18:36:48 [debug] 29836#0: *1 http proxy header: "User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.13.1.0 zlib/1.2.3 libidn/1.18 libssh2/1.2.2"
2013/02/28 18:36:48 [debug] 29836#0: *1 http proxy header: "Accept: */*"
2013/02/28 18:36:48 [debug] 29836#0: *1 http proxy header:
"GET /v1/tfs/T17yCTByJT1RCvBVdK HTTP/1.0
Host: 127.0.0.1
Connection: close
User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.13.1.0 zlib/1.2.3 libidn/1.18 libssh2/1.2.2
Accept: */*
"
2013/02/28 18:36:48 [debug] 29836#0: *1 posix_memalign: 0000000001BFA760:4096 @16
2013/02/28 18:36:48 [debug] 29836#0: *1 http cleanup add: 0000000001BFA7E0
2013/02/28 18:36:48 [debug] 29836#0: *1 get rr peer, try: 1
2013/02/28 18:36:48 [debug] 29836#0: *1 socket 9
2013/02/28 18:36:48 [debug] 29836#0: *1 epoll add connection: fd:9 ev:80000005
2013/02/28 18:36:48 [debug] 29836#0: *1 connect to 127.0.0.1:80, fd:9 #2
2013/02/28 18:36:48 [debug] 29836#0: *1 http upstream connect: -2
2013/02/28 18:36:48 [debug] 29836#0: *1 posix_memalign: 0000000001C22360:128 @16
2013/02/28 18:36:48 [debug] 29836#0: *1 event timer add: 9: 60000:1362047868513
2013/02/28 18:36:48 [debug] 29836#0: *1 http finalize request: -4, "/tfs/T17yCTByJT1RCvBVdK?" a:0, c:3
2013/02/28 18:36:48 [debug] 29836#0: *1 http request count:3 blk:0
2013/02/28 18:36:48 [debug] 29836#0: timer delta: 1
2013/02/28 18:36:48 [debug] 29836#0: posted events 0000000000000000
2013/02/28 18:36:48 [debug] 29836#0: worker cycle
2013/02/28 18:36:48 [debug] 29836#0: epoll timer: 60000
2013/02/28 18:36:48 [debug] 29836#0: epoll: fd:3 ev:0004 d:00007FE52BECE190
2013/02/28 18:36:48 [debug] 29836#0: *1 http run request: "/test_ok?"
2013/02/28 18:36:48 [debug] 29836#0: *1 http request empty handler
2013/02/28 18:36:48 [debug] 29836#0: epoll: fd:9 ev:0004 d:00007FE52BECE250
2013/02/28 18:36:48 [debug] 29836#0: *1 http upstream request: "/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:36:48 [debug] 29836#0: *1 http upstream send request handler
2013/02/28 18:36:48 [debug] 29836#0: *1 http upstream send request
2013/02/28 18:36:48 [debug] 29836#0: *1 chain writer buf fl:1 s:208
2013/02/28 18:36:48 [debug] 29836#0: *1 chain writer in: 0000000001BFA740
2013/02/28 18:36:48 [debug] 29836#0: *1 writev: 208
2013/02/28 18:36:48 [debug] 29836#0: *1 chain writer out: 0000000000000000
2013/02/28 18:36:48 [debug] 29836#0: *1 event timer del: 9: 1362047868513
2013/02/28 18:36:48 [debug] 29836#0: *1 event timer add: 9: 60000:1362047868514
2013/02/28 18:36:48 [debug] 29836#0: epoll: fd:6 ev:0001 d:00007FE52BECE010
2013/02/28 18:36:48 [debug] 29836#0: accept on 0.0.0.0:80, ready: 0
2013/02/28 18:36:48 [debug] 29836#0: posix_memalign: 0000000001BFE620:256 @16
2013/02/28 18:36:48 [debug] 29836#0: *3 accept: 127.0.0.1 fd:10
2013/02/28 18:36:48 [debug] 29836#0: *3 event timer add: 10: 60000:1362047868514
2013/02/28 18:36:48 [debug] 29836#0: *3 epoll add event: fd:10 op:1 ev:80000001
2013/02/28 18:36:48 [debug] 29836#0: timer delta: 1
2013/02/28 18:36:48 [debug] 29836#0: posted events 0000000000000000
2013/02/28 18:36:48 [debug] 29836#0: worker cycle
2013/02/28 18:36:48 [debug] 29836#0: epoll timer: 60000
2013/02/28 18:36:48 [debug] 29836#0: epoll: fd:10 ev:0001 d:00007FE52BECE310
2013/02/28 18:36:48 [debug] 29836#0: *3 malloc: 0000000001C153E0:1256
2013/02/28 18:36:48 [debug] 29836#0: *3 posix_memalign: 0000000001C158D0:256 @16
2013/02/28 18:36:48 [debug] 29836#0: *3 malloc: 0000000001BFB770:1024
2013/02/28 18:36:48 [debug] 29836#0: *3 posix_memalign: 0000000001BFBB80:4096 @16
2013/02/28 18:36:48 [debug] 29836#0: *3 http process request line
2013/02/28 18:36:48 [debug] 29836#0: *3 recv: fd:10 208 of 1024
2013/02/28 18:36:48 [debug] 29836#0: *3 http request line: "GET /v1/tfs/T17yCTByJT1RCvBVdK HTTP/1.0"
2013/02/28 18:36:48 [debug] 29836#0: *3 http uri: "/v1/tfs/T17yCTByJT1RCvBVdK"
2013/02/28 18:36:48 [debug] 29836#0: *3 http args: ""
2013/02/28 18:36:48 [debug] 29836#0: *3 http exten: ""
2013/02/28 18:36:48 [debug] 29836#0: *3 http process request header line
2013/02/28 18:36:48 [debug] 29836#0: *3 http header: "Host: 127.0.0.1"
2013/02/28 18:36:48 [debug] 29836#0: *3 http header: "Connection: close"
2013/02/28 18:36:48 [debug] 29836#0: *3 http header: "User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.13.1.0 zlib/1.2.3 libidn/1.18 libssh2/1.2.2"
2013/02/28 18:36:48 [debug] 29836#0: *3 http header: "Accept: */*"
2013/02/28 18:36:48 [debug] 29836#0: *3 http header done
2013/02/28 18:36:48 [debug] 29836#0: *3 event timer del: 10: 1362047868514
2013/02/28 18:36:48 [debug] 29836#0: *3 rewrite phase: 0
2013/02/28 18:36:48 [debug] 29836#0: *3 rewrite phase: 1
2013/02/28 18:36:48 [debug] 29836#0: *3 test location: "/"
2013/02/28 18:36:48 [debug] 29836#0: *3 test location: "tfs/"
2013/02/28 18:36:48 [debug] 29836#0: *3 test location: "v1/tfs"
2013/02/28 18:36:48 [debug] 29836#0: *3 using configuration "/v1/tfs"
2013/02/28 18:36:48 [debug] 29836#0: *3 http cl:-1 max:1048576
2013/02/28 18:36:48 [debug] 29836#0: *3 rewrite phase: 3
2013/02/28 18:36:48 [debug] 29836#0: *3 rewrite phase: 4
2013/02/28 18:36:48 [debug] 29836#0: *3 post rewrite phase: 5
2013/02/28 18:36:48 [debug] 29836#0: *3 generic phase: 6
2013/02/28 18:36:48 [debug] 29836#0: *3 generic phase: 7
2013/02/28 18:36:48 [debug] 29836#0: *3 access phase: 8
2013/02/28 18:36:48 [debug] 29836#0: *3 access phase: 9
2013/02/28 18:36:48 [debug] 29836#0: *3 access phase: 10
2013/02/28 18:36:48 [debug] 29836#0: *3 access phase: 11
2013/02/28 18:36:48 [debug] 29836#0: *3 post access phase: 12
2013/02/28 18:36:48 [debug] 29836#0: *3 try files phase: 13
2013/02/28 18:36:48 [debug] 29836#0: *3 posix_memalign: 0000000001CEA740:4096 @16
2013/02/28 18:36:48 [debug] 29836#0: *3 http set discard body
2013/02/28 18:36:48 [debug] 29836#0: *3 http init tfs, client timer: 0
2013/02/28 18:36:48 [debug] 29836#0: *3 epoll add event: fd:10 op:3 ev:80000005
2013/02/28 18:36:48 [info] 29836#0: *3 meta segment: block_id: 2262, fileid: 1, seq_id: 1, suffix: 0, client: 127.0.0.1, server: 127.0.0.1,, request: "GET /v1/tfs/T17yCTByJT1RCvBVdK HTTP/1.0", host: "127.0.0.1"
2013/02/28 18:36:48 [info] 29836#0: *3 get block info from ns while connecting server, client: 127.0.0.1, server: 127.0.0.1,, request: "GET /v1/tfs/T17yCTByJT1RCvBVdK HTTP/1.0", host: "127.0.0.1"
2013/02/28 18:36:48 [debug] 29836#0: *3 connecting name server, addr: 10.80.102.105:8108
2013/02/28 18:36:48 [debug] 29836#0: *3 get keepalive peer
2013/02/28 18:36:48 [debug] 29836#0: *3 socket 11
2013/02/28 18:36:48 [debug] 29836#0: *3 epoll add connection: fd:11 ev:80000005
2013/02/28 18:36:48 [debug] 29836#0: *3 connect to name server, fd:11 #4
2013/02/28 18:36:48 [debug] 29836#0: *3 posix_memalign: 0000000001BF4B80:128 @16
2013/02/28 18:36:48 [debug] 29836#0: *3 event timer add: 11: 3000:1362047811514
2013/02/28 18:36:48 [debug] 29836#0: *3 http finalize request: -4, "/v1/tfs/T17yCTByJT1RCvBVdK?" a:1, c:2
2013/02/28 18:36:48 [debug] 29836#0: *3 http request count:2 blk:0
2013/02/28 18:36:48 [debug] 29836#0: timer delta: 0
2013/02/28 18:36:48 [debug] 29836#0: posted events 0000000000000000
2013/02/28 18:36:48 [debug] 29836#0: worker cycle
2013/02/28 18:36:48 [debug] 29836#0: epoll timer: 3000
2013/02/28 18:36:48 [debug] 29836#0: epoll: fd:10 ev:0004 d:00007FE52BECE310
2013/02/28 18:36:48 [debug] 29836#0: *3 http run request: "/v1/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:36:48 [debug] 29836#0: *3 http request empty handler
2013/02/28 18:36:48 [debug] 29836#0: epoll: fd:11 ev:0004 d:00007FE52BECE3D0
2013/02/28 18:36:48 [debug] 29836#0: *3 http tfs request: "/v1/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:36:48 [debug] 29836#0: *3 http tfs send request
2013/02/28 18:36:48 [debug] 29836#0: *3 http tfs send request to name server, addr: 10.80.102.105:8108
2013/02/28 18:36:48 [debug] 29836#0: *3 chain writer buf fl:0 s:36
2013/02/28 18:36:48 [debug] 29836#0: *3 chain writer in: 0000000001BFCB70
2013/02/28 18:36:48 [debug] 29836#0: *3 writev: 36
2013/02/28 18:36:48 [debug] 29836#0: *3 chain writer out: 0000000000000000
2013/02/28 18:36:48 [debug] 29836#0: *3 event timer del: 11: 1362047811514
2013/02/28 18:36:48 [debug] 29836#0: *3 event timer add: 11: 3000:1362047811514
2013/02/28 18:36:48 [debug] 29836#0: timer delta: 0
2013/02/28 18:36:48 [debug] 29836#0: posted events 0000000000000000
2013/02/28 18:36:48 [debug] 29836#0: worker cycle
2013/02/28 18:36:48 [debug] 29836#0: epoll timer: 3000
2013/02/28 18:36:48 [debug] 29836#0: epoll: fd:11 ev:0005 d:00007FE52BECE3D0
2013/02/28 18:36:48 [debug] 29836#0: *3 http tfs request: "/v1/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:36:48 [debug] 29836#0: *3 http tfs process tfs(name server) data
2013/02/28 18:36:48 [debug] 29836#0: *3 http tfs process request body for name server, addr: 10.80.102.105:8108
2013/02/28 18:36:48 [debug] 29836#0: *3 malloc: 00007FE52AFCB010:2097152
2013/02/28 18:36:48 [debug] 29836#0: *3 event timer del: 11: 1362047811514
2013/02/28 18:36:48 [debug] 29836#0: *3 readv: 2:2097152
2013/02/28 18:36:48 [debug] 29836#0: *3 insert local block cache, ns addr: 34825363148810, block id: 2262
2013/02/28 18:36:48 [debug] 29836#0: shmtx lock
2013/02/28 18:36:48 [debug] 29836#0: slab alloc: 88 slot: 4
2013/02/28 18:36:48 [debug] 29836#0: slab alloc: 00007FE52CC4D080
2013/02/28 18:36:48 [debug] 29836#0: shmtx unlock
2013/02/28 18:36:48 [debug] 29836#0: *3 get block info from nameserver: , block id: 2262, ds count: 2, version: 0, lease id: 0
2013/02/28 18:36:48 [debug] 29836#0: *3 select data server, ds_retry: 0, ds_index: 0
2013/02/28 18:36:48 [info] 29836#0: *3 http tfs finalize state name server, 0 while reading response header from tfs, client: 127.0.0.1, server: 127.0.0.1,, request: "GET /v1/tfs/T17yCTByJT1RCvBVdK HTTP/1.0", host: "127.0.0.1"
2013/02/28 18:36:48 [debug] 29836#0: *3 free keepalive peer
2013/02/28 18:36:48 [debug] 29836#0: *3 free keepalive peer: saving connection 00007FE52BECE3D0
2013/02/28 18:36:48 [debug] 29836#0: keepalive close handler
2013/02/28 18:36:48 [info] 29836#0: *3 http tfs process next peer is data server, addr: 10.80.102.100:9998 while reading response header from tfs, client: 127.0.0.1, server: 127.0.0.1,, request: "GET /v1/tfs/T17yCTByJT1RCvBVdK HTTP/1.0", host: "127.0.0.1"
2013/02/28 18:36:48 [info] 29836#0: *3 read segment index 0, block id: 2262, file id: 1, offset: 0, length: 524288 while connecting server, client: 127.0.0.1, server: 127.0.0.1,, request: "GET /v1/tfs/T17yCTByJT1RCvBVdK HTTP/1.0", host: "127.0.0.1"
2013/02/28 18:36:48 [debug] 29836#0: *3 connecting data server, addr: 10.80.102.100:9998
2013/02/28 18:36:48 [debug] 29836#0: *3 get keepalive peer
2013/02/28 18:36:48 [debug] 29836#0: *3 socket 12
2013/02/28 18:36:48 [debug] 29836#0: *3 epoll add connection: fd:12 ev:80000005
2013/02/28 18:36:48 [debug] 29836#0: *3 connect to data server, fd:12 #5
2013/02/28 18:36:48 [debug] 29836#0: *3 posix_memalign: 0000000001BF4C10:128 @16
2013/02/28 18:36:48 [debug] 29836#0: *3 event timer add: 12: 3000:1362047811515
2013/02/28 18:36:48 [debug] 29836#0: keepalive dummy handler
2013/02/28 18:36:48 [debug] 29836#0: timer delta: 1
2013/02/28 18:36:48 [debug] 29836#0: posted events 0000000000000000
2013/02/28 18:36:48 [debug] 29836#0: worker cycle
2013/02/28 18:36:48 [debug] 29836#0: epoll timer: 3000
2013/02/28 18:36:48 [debug] 29836#0: epoll: fd:12 ev:0004 d:00007FE52BECE490
2013/02/28 18:36:48 [debug] 29836#0: *3 http tfs request: "/v1/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:36:48 [debug] 29836#0: *3 http tfs send request
2013/02/28 18:36:48 [debug] 29836#0: *3 http tfs send request to data server, addr: 10.80.102.100:9998
2013/02/28 18:36:48 [debug] 29836#0: *3 chain writer buf fl:0 s:45
2013/02/28 18:36:48 [debug] 29836#0: *3 chain writer in: 0000000001CEB688
2013/02/28 18:36:48 [debug] 29836#0: *3 writev: 45
2013/02/28 18:36:48 [debug] 29836#0: *3 chain writer out: 0000000000000000
2013/02/28 18:36:48 [debug] 29836#0: *3 event timer del: 12: 1362047811515
2013/02/28 18:36:48 [debug] 29836#0: *3 event timer add: 12: 3000:1362047811515
2013/02/28 18:36:48 [debug] 29836#0: timer delta: 0
2013/02/28 18:36:48 [debug] 29836#0: posted events 0000000000000000
2013/02/28 18:36:48 [debug] 29836#0: worker cycle
2013/02/28 18:36:48 [debug] 29836#0: epoll timer: 3000
2013/02/28 18:36:48 [debug] 29836#0: epoll: fd:12 ev:0005 d:00007FE52BECE490
2013/02/28 18:36:48 [debug] 29836#0: *3 http tfs request: "/v1/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:36:48 [debug] 29836#0: *3 http tfs process tfs(data server) data
2013/02/28 18:36:48 [debug] 29836#0: *3 http tfs process request body for data server, addr: 10.80.102.100:9998
2013/02/28 18:36:48 [debug] 29836#0: *3 malloc: 00007FE52ADCA010:2097152
2013/02/28 18:36:48 [debug] 29836#0: *3 event timer del: 12: 1362047811515
2013/02/28 18:36:48 [debug] 29836#0: *3 readv: 2:2097152
2013/02/28 18:36:48 [debug] 29836#0: *3 read len is 135, data len is 95
2013/02/28 18:36:48 [debug] 29836#0: *3 t->length is 0, rc is 0
2013/02/28 18:36:48 [info] 29836#0: *3 http tfs finalize state data server, -4 while reading response header from tfs, client: 127.0.0.1, server: 127.0.0.1,, request: "GET /v1/tfs/T17yCTByJT1RCvBVdK HTTP/1.0", host: "127.0.0.1"
2013/02/28 18:36:48 [info] 29836#0: *3 read_file success while reading response header from tfs, client: 127.0.0.1, server: 127.0.0.1,, request: "GET /v1/tfs/T17yCTByJT1RCvBVdK HTTP/1.0", host: "127.0.0.1"
2013/02/28 18:36:48 [debug] 29836#0: *3 lua capture header filter, uri "/v1/tfs/T17yCTByJT1RCvBVdK"
2013/02/28 18:36:48 [debug] 29836#0: *3 posix_memalign: 0000000001CEB750:4096 @16
2013/02/28 18:36:48 [debug] 29836#0: *3 HTTP/1.1 200 OK
Server: ngx_openresty
Date: Thu, 28 Feb 2013 10:36:48 GMT
Connection: close
2013/02/28 18:36:48 [debug] 29836#0: *3 write new buf t:1 f:0 0000000001CEB7C0, pos 0000000001CEB7C0, size: 98 file: 0, size: 0
2013/02/28 18:36:48 [debug] 29836#0: *3 http write filter: l:0 f:0 s:98
2013/02/28 18:36:48 [debug] 29836#0: *3 tcp_nodelay
2013/02/28 18:36:48 [debug] 29836#0: *3 http tfs upstream process downstream
2013/02/28 18:36:48 [debug] 29836#0: *3 http output filter "/v1/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:36:48 [debug] 29836#0: *3 http copy filter: "/v1/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:36:48 [debug] 29836#0: *3 lua capture body filter, uri "/v1/tfs/T17yCTByJT1RCvBVdK"
2013/02/28 18:36:48 [debug] 29836#0: *3 http postpone filter "/v1/tfs/T17yCTByJT1RCvBVdK?" 0000000001CEB6A8
2013/02/28 18:36:48 [debug] 29836#0: *3 write old buf t:1 f:0 0000000001CEB7C0, pos 0000000001CEB7C0, size: 98 file: 0, size: 0
2013/02/28 18:36:48 [debug] 29836#0: *3 write new buf t:0 f:0 0000000000000000, pos 00007FE52ADCA010, size: 95 file: 0, size: 0
2013/02/28 18:36:48 [debug] 29836#0: *3 http write filter: l:0 f:1 s:193
2013/02/28 18:36:48 [debug] 29836#0: *3 http write filter limit 0
2013/02/28 18:36:48 [debug] 29836#0: *3 writev: 193
2013/02/28 18:36:48 [debug] 29836#0: *3 http write filter 0000000000000000
2013/02/28 18:36:48 [debug] 29836#0: *3 http copy filter: 0 "/v1/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:36:48 [info] 29836#0: *3 read_file , output 2097152 byte while sending to client, client: 127.0.0.1, server: 127.0.0.1,, request: "GET /v1/tfs/T17yCTByJT1RCvBVdK HTTP/1.0", host: "127.0.0.1"
2013/02/28 18:36:48 [debug] 29836#0: *3 finalize http tfs request: 0
2013/02/28 18:36:48 [debug] 29836#0: *3 free keepalive peer
2013/02/28 18:36:48 [debug] 29836#0: *3 free keepalive peer
2013/02/28 18:36:48 [debug] 29836#0: *3 free keepalive peer: saving connection 00007FE52BECE490
2013/02/28 18:36:48 [debug] 29836#0: keepalive close handler
2013/02/28 18:36:48 [debug] 29836#0: *3 <== conn pool check ==> all keepalive peers are free
2013/02/28 18:36:48 [debug] 29836#0: *3 http output filter "/v1/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:36:48 [debug] 29836#0: *3 http copy filter: "/v1/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:36:48 [debug] 29836#0: *3 lua capture body filter, uri "/v1/tfs/T17yCTByJT1RCvBVdK"
2013/02/28 18:36:48 [debug] 29836#0: *3 http postpone filter "/v1/tfs/T17yCTByJT1RCvBVdK?" 00007FFF069CDCD0
2013/02/28 18:36:48 [debug] 29836#0: *3 write new buf t:0 f:0 0000000000000000, pos 0000000000000000, size: 0 file: 0, size: 0
2013/02/28 18:36:48 [debug] 29836#0: *3 http write filter: l:1 f:0 s:0
2013/02/28 18:36:48 [debug] 29836#0: *3 http copy filter: 0 "/v1/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:36:48 [debug] 29836#0: *3 http finalize request: 0, "/v1/tfs/T17yCTByJT1RCvBVdK?" a:1, c:1
2013/02/28 18:36:48 [debug] 29836#0: *3 event timer add: 10: 5000:1362047813515
2013/02/28 18:36:48 [debug] 29836#0: *3 http lingering close handler
2013/02/28 18:36:48 [debug] 29836#0: *3 recv: fd:10 -1 of 4096
2013/02/28 18:36:48 [debug] 29836#0: *3 recv() not ready (11: Resource temporarily unavailable)
2013/02/28 18:36:48 [debug] 29836#0: *3 lingering read: -2
2013/02/28 18:36:48 [debug] 29836#0: *3 event timer: 10, old: 1362047813515, new: 1362047813515
2013/02/28 18:36:48 [debug] 29836#0: keepalive dummy handler
2013/02/28 18:36:48 [debug] 29836#0: timer delta: 0
2013/02/28 18:36:48 [debug] 29836#0: posted events 0000000000000000
2013/02/28 18:36:48 [debug] 29836#0: worker cycle
2013/02/28 18:36:48 [debug] 29836#0: epoll timer: 5000
2013/02/28 18:36:48 [debug] 29836#0: epoll: fd:9 ev:0005 d:00007FE52BECE250
2013/02/28 18:36:48 [debug] 29836#0: *1 http upstream request: "/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:36:48 [debug] 29836#0: *1 http upstream process header
2013/02/28 18:36:48 [debug] 29836#0: *1 malloc: 0000000001CEC760:4096
2013/02/28 18:36:48 [debug] 29836#0: *1 recv: fd:9 193 of 4096
2013/02/28 18:36:48 [debug] 29836#0: *1 http proxy status 200 "200 OK"
2013/02/28 18:36:48 [debug] 29836#0: *1 http proxy header: "Server: ngx_openresty"
2013/02/28 18:36:48 [debug] 29836#0: *1 http proxy header: "Date: Thu, 28 Feb 2013 10:36:48 GMT"
2013/02/28 18:36:48 [debug] 29836#0: *1 http proxy header: "Connection: close"
2013/02/28 18:36:48 [debug] 29836#0: *1 http proxy header done
2013/02/28 18:36:48 [debug] 29836#0: *1 lua capture header filter, uri "/tfs/T17yCTByJT1RCvBVdK"
2013/02/28 18:36:48 [debug] 29836#0: *1 lua capturing response body
2013/02/28 18:36:48 [debug] 29836#0: *1 http cacheable: 0
2013/02/28 18:36:48 [debug] 29836#0: *1 http proxy filter init s:200 h:0 c:0 l:-1
2013/02/28 18:36:48 [debug] 29836#0: *1 http upstream process upstream
2013/02/28 18:36:48 [debug] 29836#0: *1 pipe read upstream: 1
2013/02/28 18:36:48 [debug] 29836#0: *1 pipe preread: 95
2013/02/28 18:36:48 [debug] 29836#0: *1 readv: 1:3903
2013/02/28 18:36:48 [debug] 29836#0: *1 pipe recv chain: 0
2013/02/28 18:36:48 [debug] 29836#0: *1 pipe buf free s:0 t:1 f:0 0000000001CEC760, pos 0000000001CEC7C2, size: 95 file: 0, size: 0
2013/02/28 18:36:48 [debug] 29836#0: *1 pipe length: -1
2013/02/28 18:36:48 [debug] 29836#0: *1 input buf #0
2013/02/28 18:36:48 [debug] 29836#0: *1 pipe write downstream: 1
2013/02/28 18:36:48 [debug] 29836#0: *1 pipe write downstream flush in
2013/02/28 18:36:48 [debug] 29836#0: *1 http output filter "/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:36:48 [debug] 29836#0: *1 http copy filter: "/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:36:48 [debug] 29836#0: *1 lua capture body filter, uri "/tfs/T17yCTByJT1RCvBVdK"
2013/02/28 18:36:48 [debug] 29836#0: *1 lua capture body filter capturing response body, uri "/tfs/T17yCTByJT1RCvBVdK"
2013/02/28 18:36:48 [debug] 29836#0: *1 lua allocate new chainlink and new buf of size 95, cl:0000000001BFABE0
2013/02/28 18:36:48 [debug] 29836#0: *1 http copy filter: 0 "/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:36:48 [debug] 29836#0: *1 pipe write downstream done
2013/02/28 18:36:48 [debug] 29836#0: *1 event timer: 9, old: 1362047868514, new: 1362047868516
2013/02/28 18:36:48 [debug] 29836#0: *1 http upstream exit: 0000000000000000
2013/02/28 18:36:48 [debug] 29836#0: *1 finalize http upstream request: 0
2013/02/28 18:36:48 [debug] 29836#0: *1 finalize http proxy request
2013/02/28 18:36:48 [debug] 29836#0: *1 free rr peer 1 0
2013/02/28 18:36:48 [debug] 29836#0: *1 close http upstream connection: 9
2013/02/28 18:36:48 [debug] 29836#0: *1 free: 0000000001C22360, unused: 48
2013/02/28 18:36:48 [debug] 29836#0: *1 event timer del: 9: 1362047868514
2013/02/28 18:36:48 [debug] 29836#0: *1 reusable connection: 0
2013/02/28 18:36:48 [debug] 29836#0: *1 http upstream temp fd: -1
2013/02/28 18:36:48 [debug] 29836#0: *1 http output filter "/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:36:48 [debug] 29836#0: *1 http copy filter: "/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:36:48 [debug] 29836#0: *1 lua capture body filter, uri "/tfs/T17yCTByJT1RCvBVdK"
2013/02/28 18:36:48 [debug] 29836#0: *1 lua capture body filter capturing response body, uri "/tfs/T17yCTByJT1RCvBVdK"
2013/02/28 18:36:48 [debug] 29836#0: *1 http copy filter: 0 "/tfs/T17yCTByJT1RCvBVdK?"
2013/02/28 18:36:48 [debug] 29836#0: *1 http finalize request: 0, "/tfs/T17yCTByJT1RCvBVdK?" a:0, c:2
2013/02/28 18:36:48 [debug] 29836#0: *1 lua run post subrequest handler, rc:0 c:2
2013/02/28 18:36:48 [debug] 29836#0: *1 lua restoring write event handler
2013/02/28 18:36:48 [debug] 29836#0: *1 http wake parent request: "/test_ok?"
2013/02/28 18:36:48 [debug] 29836#0: *1 http posted request: "/test_ok?"
2013/02/28 18:36:48 [debug] 29836#0: *1 lua run subrequests done, resuming lua thread
2013/02/28 18:36:48 [debug] 29836#0: *1 lua handle subrequest responses
2013/02/28 18:36:48 [debug] 29836#0: *1 lua run thread, top:0 c:1
2013/02/28 18:36:48 [debug] 29836#0: *1 lua reuse free buf memory 95 >= 95, cl:0000000001BFABE0, p:0000000001BFAC40
2013/02/28 18:36:48 [debug] 29836#0: *1 lua print response
2013/02/28 18:36:48 [debug] 29836#0: *1 lua capture header filter, uri "/test_ok"
2013/02/28 18:36:48 [debug] 29836#0: *1 HTTP/1.1 200 OK
Server: ngx_openresty
Date: Thu, 28 Feb 2013 10:36:48 GMT
Content-Type: application/octet-stream
Transfer-Encoding: chunked
Connection: keep-alive
2013/02/28 18:36:48 [debug] 29836#0: *1 write new buf t:1 f:0 0000000001BFADD0, pos 0000000001BFADD0, size: 171 file: 0, size: 0
2013/02/28 18:36:48 [debug] 29836#0: *1 http write filter: l:0 f:0 s:171
2013/02/28 18:36:48 [debug] 29836#0: *1 http output filter "/test_ok?"
2013/02/28 18:36:48 [debug] 29836#0: *1 http copy filter: "/test_ok?"
2013/02/28 18:36:48 [debug] 29836#0: *1 lua capture body filter, uri "/test_ok"
2013/02/28 18:36:48 [debug] 29836#0: *1 http postpone filter "/test_ok?" 0000000001BFABE0
2013/02/28 18:36:48 [debug] 29836#0: *1 http chunk: 95
2013/02/28 18:36:48 [debug] 29836#0: *1 write old buf t:1 f:0 0000000001BFADD0, pos 0000000001BFADD0, size: 171 file: 0, size: 0
2013/02/28 18:36:48 [debug] 29836#0: *1 write new buf t:1 f:0 0000000001BFAF68, pos 0000000001BFAF68, size: 4 file: 0, size: 0
2013/02/28 18:36:48 [debug] 29836#0: *1 write new buf t:1 f:0 0000000001BFAC40, pos 0000000001BFAC40, size: 95 file: 0, size: 0
2013/02/28 18:36:48 [debug] 29836#0: *1 write new buf t:0 f:0 0000000000000000, pos 0000000000569C28, size: 2 file: 0, size: 0
2013/02/28 18:36:48 [debug] 29836#0: *1 http write filter: l:0 f:0 s:272
2013/02/28 18:36:48 [debug] 29836#0: *1 http copy filter: 0 "/test_ok?"
2013/02/28 18:36:48 [debug] 29836#0: *1 lua resume returned 0
2013/02/28 18:36:48 [debug] 29836#0: *1 lua light thread ended normally
2013/02/28 18:36:48 [debug] 29836#0: *1 lua deleting light thread
2013/02/28 18:36:48 [debug] 29836#0: *1 lua sending last buf of the response body
2013/02/28 18:36:48 [debug] 29836#0: *1 http output filter "/test_ok?"
2013/02/28 18:36:48 [debug] 29836#0: *1 http copy filter: "/test_ok?"
2013/02/28 18:36:48 [debug] 29836#0: *1 lua capture body filter, uri "/test_ok"
2013/02/28 18:36:48 [debug] 29836#0: *1 http postpone filter "/test_ok?" 00007FFF069CDD30
2013/02/28 18:36:48 [debug] 29836#0: *1 http chunk: 0
2013/02/28 18:36:48 [debug] 29836#0: *1 write old buf t:1 f:0 0000000001BFADD0, pos 0000000001BFADD0, size: 171 file: 0, size: 0
2013/02/28 18:36:48 [debug] 29836#0: *1 write old buf t:1 f:0 0000000001BFAF68, pos 0000000001BFAF68, size: 4 file: 0, size: 0
2013/02/28 18:36:48 [debug] 29836#0: *1 write old buf t:1 f:0 0000000001BFAC40, pos 0000000001BFAC40, size: 95 file: 0, size: 0
2013/02/28 18:36:48 [debug] 29836#0: *1 write old buf t:0 f:0 0000000000000000, pos 0000000000569C28, size: 2 file: 0, size: 0
2013/02/28 18:36:48 [debug] 29836#0: *1 write new buf t:0 f:0 0000000000000000, pos 0000000000569C22, size: 5 file: 0, size: 0
2013/02/28 18:36:48 [debug] 29836#0: *1 http write filter: l:1 f:0 s:277
2013/02/28 18:36:48 [debug] 29836#0: *1 http write filter limit 0
2013/02/28 18:36:48 [debug] 29836#0: *1 writev: 277
2013/02/28 18:36:48 [debug] 29836#0: *1 http write filter 0000000000000000
2013/02/28 18:36:48 [debug] 29836#0: *1 http copy filter: 0 "/test_ok?"
2013/02/28 18:36:48 [debug] 29836#0: *1 lua run thread returned 0
2013/02/28 18:36:48 [debug] 29836#0: *1 http finalize request: 0, "/test_ok?" a:1, c:1
2013/02/28 18:36:48 [debug] 29836#0: *1 set http keepalive handler
2013/02/28 18:36:48 [debug] 29836#0: *1 http close request
2013/02/28 18:36:48 [debug] 29836#0: *1 lua request cleanup
2013/02/28 18:36:48 [debug] 29836#0: *1 http log handler
2013/02/28 18:36:48 [debug] 29836#0: *1 free: 0000000001CEC760
2013/02/28 18:36:48 [debug] 29836#0: *1 free: 0000000001C143D0, unused: 0
2013/02/28 18:36:48 [debug] 29836#0: *1 free: 0000000001BF9750, unused: 0
2013/02/28 18:36:48 [debug] 29836#0: *1 free: 0000000001BFA760, unused: 1431
2013/02/28 18:36:48 [debug] 29836#0: *1 event timer add: 3: 65000:1362047873516
2013/02/28 18:36:48 [debug] 29836#0: *1 free: 0000000001BFE020
2013/02/28 18:36:48 [debug] 29836#0: *1 free: 0000000001C13FC0
2013/02/28 18:36:48 [debug] 29836#0: *1 hc free: 0000000000000000 0
2013/02/28 18:36:48 [debug] 29836#0: *1 hc busy: 0000000000000000 0
2013/02/28 18:36:48 [debug] 29836#0: *1 tcp_nodelay
2013/02/28 18:36:48 [debug] 29836#0: *1 reusable connection: 1
2013/02/28 18:36:48 [debug] 29836#0: *1 post event 00007FE52B84D0E0
2013/02/28 18:36:48 [debug] 29836#0: timer delta: 1
2013/02/28 18:36:48 [debug] 29836#0: posted events 00007FE52B84D0E0
2013/02/28 18:36:48 [debug] 29836#0: posted event 00007FE52B84D0E0
2013/02/28 18:36:48 [debug] 29836#0: *1 delete posted event 00007FE52B84D0E0
2013/02/28 18:36:48 [debug] 29836#0: *1 http keepalive handler
2013/02/28 18:36:48 [debug] 29836#0: *1 malloc: 0000000001BFE020:1024
2013/02/28 18:36:48 [debug] 29836#0: *1 recv: fd:3 0 of 1024
2013/02/28 18:36:48 [info] 29836#0: *1 client 127.0.0.1 closed keepalive connection
2013/02/28 18:36:48 [debug] 29836#0: *1 close http connection: 3
2013/02/28 18:36:48 [debug] 29836#0: *1 event timer del: 3: 1362047873516
2013/02/28 18:36:48 [debug] 29836#0: *1 reusable connection: 0
2013/02/28 18:36:48 [debug] 29836#0: *1 free: 0000000001BFE020
2013/02/28 18:36:48 [debug] 29836#0: *1 free: 0000000000000000
2013/02/28 18:36:48 [debug] 29836#0: *1 free: 0000000001BF4A20, unused: 8
2013/02/28 18:36:48 [debug] 29836#0: *1 free: 0000000001BFE510, unused: 128
2013/02/28 18:36:48 [debug] 29836#0: posted event 0000000000000000
2013/02/28 18:36:48 [debug] 29836#0: worker cycle
2013/02/28 18:36:48 [debug] 29836#0: epoll timer: 4999
2013/02/28 18:36:48 [debug] 29836#0: epoll: fd:10 ev:0011 d:00007FE52BECE310
2013/02/28 18:36:48 [debug] 29836#0: epoll_wait() error on fd:10 ev:0011
2013/02/28 18:36:48 [debug] 29836#0: *3 http lingering close handler
2013/02/28 18:36:48 [debug] 29836#0: *3 recv: fd:10 0 of 4096
2013/02/28 18:36:48 [debug] 29836#0: *3 lingering read: 0
2013/02/28 18:36:48 [debug] 29836#0: *3 http request count:1 blk:0
2013/02/28 18:36:48 [debug] 29836#0: *3 http close request
2013/02/28 18:36:48 [debug] 29836#0: *3 http log handler
2013/02/28 18:36:48 [debug] 29836#0: *3 free: 00007FE52ADCA010
2013/02/28 18:36:48 [debug] 29836#0: *3 free: 00007FE52AFCB010
2013/02/28 18:36:48 [debug] 29836#0: *3 free: 0000000001BFBB80, unused: 0
2013/02/28 18:36:48 [debug] 29836#0: *3 free: 0000000001CEA740, unused: 24
2013/02/28 18:36:48 [debug] 29836#0: *3 free: 0000000001CEB750, unused: 3429
2013/02/28 18:36:48 [debug] 29836#0: *3 close http connection: 10
2013/02/28 18:36:48 [debug] 29836#0: *3 event timer del: 10: 1362047813515
2013/02/28 18:36:48 [debug] 29836#0: *3 reusable connection: 0
2013/02/28 18:36:48 [debug] 29836#0: *3 free: 0000000001BFB770
2013/02/28 18:36:48 [debug] 29836#0: *3 free: 0000000001C153E0
2013/02/28 18:36:48 [debug] 29836#0: *3 free: 0000000001BFE620, unused: 8
2013/02/28 18:36:48 [debug] 29836#0: *3 free: 0000000001C158D0, unused: 128
2013/02/28 18:36:48 [debug] 29836#0: timer delta: 1
2013/02/28 18:36:48 [debug] 29836#0: posted events 0000000000000000
2013/02/28 18:36:48 [debug] 29836#0: worker cycle
2013/02/28 18:36:48 [debug] 29836#0: epoll timer: -1
worker_processes 1;
error_log logs/error.log debug;
pid logs/nginx.pid;
worker_rlimit_nofile 65535 ;
events {
worker_connections 65536;
}
http {
include mime.types;
default_type application/octet-stream;
log_format main '$remote_addr - $remote_user [$time_local] "$request" '
'$status $body_bytes_sent "$http_referer" '
'"$http_user_agent" "$http_x_forwarded_for" '
'$request_time $upstream_response_time';
access_log logs/access.log main;
sendfile on;
keepalive_timeout 65;
server_tokens off;
tfs_upstream tfs_ups {
server 10.80.102.105:8108;
type ns;
rcs_interface bond0;
rcs_zone name=tfs1 size=128M;
rcs_heartbeat lock_file=/logs/lk.file interval=10s;
}
tfs_block_cache_zone size=256M;
tfs_send_timeout 3s;
tfs_connect_timeout 3s;
tfs_read_timeout 3s;
tfs_body_buffer_size 2m;
lua_package_path "/home/server/openresty-debug/nginx/lualib/?.lua;/home/server/openresty-debug/nginx/conf/lua/?.lua;;";
lua_package_cpath "/usr/lib64/lua/5.1/?.so;;";
upstream nginx_tfs {
server 10.80.102.100:80 ;
}
server {
listen 80 backlog=4096;
server_name 127.0.0.1, localhost;
tfs_keepalive max_cached=100 bucket_count=10;
location / {
root /data/;
try_files $uri $uri/;
}
location /v1/tfs {
tfs_pass tfs://tfs_ups;
}
location /test_block {
content_by_lua '
res = ngx.location.capture("/v1/tfs/T17yCTByJT1RCvBVdK")
if res.status == ngx.HTTP_OK then
ngx.print(res.body)
else
ngx.exit(res.status)
end
';
}
location /tfs/ {
proxy_pass http://127.0.0.1/v1/tfs/;
}
location /test_ok {
content_by_lua '
res = ngx.location.capture("/tfs/T17yCTByJT1RCvBVdK")
if res.status == ngx.HTTP_OK then
ngx.print(res.body)
else
ngx.exit(res.status)
end
';
}
}
}
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment