Created
July 14, 2017 16:33
-
-
Save macejmic/ebca5d7b9c1861c776fb1755fd6ae29b to your computer and use it in GitHub Desktop.
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| ➜ wildcard-service git:(wildcard-test) ✗ git diff | |
| ➜ wildcard-service git:(wildcard-test) ✗ make prove | |
| TEST_NGINX_ERROR_LOG=/dev/stderr TEST_NGINX_BINARY=openresty prove | |
| t/001-wildcard-router.t .. 1/? | |
| # Failed test 'ERROR: client socket timed out - TEST 2: request though the wildcard router using the API | |
| # ' | |
| # at /Library/Perl/5.18/Test/Nginx/Socket.pm line 1815. | |
| # Failed test 'TEST 2: request though the wildcard router using the API - status code ok' | |
| # at /Library/Perl/5.18/Test/Nginx/Socket.pm line 922. | |
| # got: '' | |
| # expected: '200' | |
| === t/001-wildcard-router.t TEST 2: request though the wildcard router using the API | |
| 2017/07/14 18:33:28 [debug] 68726#950738: bind() 0.0.0.0:1953 #7 | |
| 2017/07/14 18:33:28 [debug] 68726#950738: bind() 0.0.0.0:1984 #8 | |
| 2017/07/14 18:33:28 [notice] 68726#950738: using the "kqueue" event method | |
| 2017/07/14 18:33:28 [notice] 68726#950738: openresty/1.11.2.3 | |
| 2017/07/14 18:33:28 [notice] 68726#950738: built by clang 8.0.0 (clang-800.0.42.1) | |
| 2017/07/14 18:33:28 [notice] 68726#950738: OS: Darwin 15.6.0 | |
| 2017/07/14 18:33:28 [notice] 68726#950738: hw.ncpu: 4 | |
| 2017/07/14 18:33:28 [notice] 68726#950738: net.inet.tcp.sendspace: 131072 | |
| 2017/07/14 18:33:28 [notice] 68726#950738: kern.ipc.somaxconn: 128 | |
| 2017/07/14 18:33:28 [notice] 68726#950738: getrlimit(RLIMIT_NOFILE): 4864:9223372036854775807 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: write: 9, 00007FFF507FF090, 6, 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: malloc: 00007FC5E3000000:16384 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: malloc: 00007FC5E3004000:16384 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: malloc: 00007FC5E3008000:15360 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: malloc: 00007FC5E300BC00:6656 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: malloc: 00007FC5E300D600:6656 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: kevent set event: 7: ft:-1 fl:0005 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: kevent set event: 8: ft:-1 fl:0005 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: worker cycle | |
| 2017/07/14 18:33:28 [debug] 68727#950739: kevent timer: -1, changes: 2 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: kevent events: 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: kevent: 8: ft:-1 fl:0005 ff:00000000 d:1 ud:00007FC5E300BC68 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: accept on 0.0.0.0:1984, ready: 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: posix_memalign: 00007FC5E1E00090:512 @16 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 accept: 127.0.0.1:50813 fd:9 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 event timer add: 9: 60000:1500050068869 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 reusable connection: 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 kevent set event: 9: ft:-1 fl:0025 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: timer delta: 30 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: worker cycle | |
| 2017/07/14 18:33:28 [debug] 68727#950739: kevent timer: 60000, changes: 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: kevent events: 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: kevent: 9: ft:-1 fl:0025 ff:00000000 d:76 ud:00007FC5E300BCD0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 http wait request handler | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 malloc: 00007FC5E2801400:1024 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 recv: eof:0, avail:76, err:0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 recv: fd:9 76 of 1024 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 reusable connection: 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 posix_memalign: 00007FC5E2801800:4096 @16 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 http process request line | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 http request line: "GET / HTTP/1.1" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 http uri: "/" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 http args: "" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 http exten: "" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 posix_memalign: 00007FC5E3800000:4096 @16 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 http process request header line | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 http header: "Connection: close" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 http header: "Host: foo-apicast-staging.example.com" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 http header done | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 event timer del: 9: 1500050068869 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 generic phase: 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 rewrite phase: 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 rewrite phase: 2 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 test location: "/" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 using configuration "/" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 http cl:-1 max:31457280 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 rewrite phase: 4 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 rewrite phase: 5 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 post rewrite phase: 6 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 generic phase: 7 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 generic phase: 8 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 generic phase: 9 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 access phase: 10 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua access handler, uri:"/" c:1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 access phase: 10 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 access phase: 11 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 access phase: 12 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 access phase: 13 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua access handler, uri:"/" c:1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua creating new thread | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua reset ctx | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 http cleanup add: 00007FC5E2802618 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua run thread, top:0 c:1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: malloc: 000000000F442000:622464 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: new block, alloc semaphore: 000000000F442018 block: 000000000F442000 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: http lua semaphore new: 000000000F442018, resources: 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 [lua] env.lua:25: fetch(): env: OPENSSL_VERIFY = nil | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua create ngx.ctx table for the current request | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 add cleanup: 00007FC5E2802630 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: http lua semaphore wait: 000000000F442018, timeout: 0, resources: 1, event posted: 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 [lua] resolver.lua:73: parse_nameservers(): /etc/resolv.conf: | |
| # | |
| # Mac OS X Notice | |
| # | |
| # This file is not used by the host name and address resolution | |
| # or the DNS query routing mechanisms used by most processes on | |
| # this Mac OS X system. | |
| # | |
| # This file is automatically generated. | |
| # | |
| domain localdomain | |
| nameserver 192.168.0.1 | |
| nameserver 192.168.0.1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 [lua] resolver.lua:80: parse_nameservers(): search nil | |
| 2017/07/14 18:33:28 [debug] 68727#950739: posix_memalign: 00007FC5E1D00740:512 @16 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: posix_memalign: 00007FC5E1D00940:512 @16 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: malloc: 00007FC5E3801000:4096 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: malloc: 00007FC5E3802400:4096 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: free: 00007FC5E3801000 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: free: 00007FC5E3802400 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: pcre JIT compiling result: 1 | |
| 2017/07/14 18:33:28 [info] 68727#950739: *1 [lua] resolver.lua:108: init_nameservers(): adding 127.0.0.1:1953 as default nameserver, client: 127.0.0.1, server: foo-apicast-staging.example.com, request: "GET / HTTP/1.1", host: "foo-apicast-staging.example.com" | |
| 2017/07/14 18:33:28 [info] 68727#950739: *1 [lua] resolver.lua:108: init_nameservers(): adding 192.168.0.1:53 as default nameserver, client: 127.0.0.1, server: foo-apicast-staging.example.com, request: "GET / HTTP/1.1", host: "foo-apicast-staging.example.com" | |
| 2017/07/14 18:33:28 [info] 68727#950739: *1 [lua] resolver.lua:108: init_nameservers(): adding 192.168.0.1:53 as default nameserver, client: 127.0.0.1, server: foo-apicast-staging.example.com, request: "GET / HTTP/1.1", host: "foo-apicast-staging.example.com" | |
| 2017/07/14 18:33:28 [info] 68727#950739: *1 [lua] resolver.lua:113: init_nameservers(): adding as search domain, client: 127.0.0.1, server: foo-apicast-staging.example.com, request: "GET / HTTP/1.1", host: "foo-apicast-staging.example.com" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: http lua semaphore post: 000000000F442018, n: 1, resources: 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua fetching existing ngx.ctx table for the current request | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 [lua] resolver.lua:141: new(): resolver search domains: | |
| 2017/07/14 18:33:28 [debug] 68727#950739: posix_memalign: 00007FC5E1D00B40:512 @16 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: malloc: 00007FC5E1D00D40:500 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: posix_memalign: 00007FC5E1D00F40:512 @16 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: malloc: 00007FC5E3802400:4096 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: malloc: 00007FC5E3801000:4096 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: malloc: 00007FC5E3803400:4096 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: free: 00007FC5E1D00D40 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: free: 00007FC5E3802400 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: free: 00007FC5E3803400 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: free: 00007FC5E3801000 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: pcre JIT compiling result: 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua fetching existing ngx.ctx table for the current request | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua regex cache miss for match regex "^(?:(http[s]?):)?//([^:/\?]+)(?::(\d+))?([^\?]*)\??(.*)" with options "jo" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua compiling match regex "^(?:(http[s]?):)?//([^:/\?]+)(?::(\d+))?([^\?]*)\??(.*)" with options "jo" (compile once: 1) (dfa mode: 0) (jit mode: 1) | |
| 2017/07/14 18:33:28 [debug] 68727#950739: malloc: 00007FC5E3801000:4096 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: malloc: 00007FC5E3802400:4096 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: malloc: 00007FC5E3803400:4096 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: free: 00007FC5E3801000 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: free: 00007FC5E3803400 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: free: 00007FC5E3802400 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 pcre JIT compiling result: 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua saving compiled regex (5 captures) into the cache (entries 0) | |
| 2017/07/14 18:33:28 [debug] 68727#950739: from head of free queue, alloc semaphore: 000000000F4420B0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: http lua semaphore new: 000000000F4420B0, resources: 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: http lua semaphore wait: 000000000F4420B0, timeout: 0, resources: 1, event posted: 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 [lua] cache.lua:118: fetch_answers(): resolver cache miss api.example.com | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 [lua] cache.lua:184: get(): resolver cache miss: api.example.com | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 [lua] resolver.lua:221: lookup(): resolver query: api.example.com | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua regex cache miss for match regex "^(?:[0-9]{1,3}\.){3}[0-9]{1,3}$" with options "oj" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua compiling match regex "^(?:[0-9]{1,3}\.){3}[0-9]{1,3}$" with options "oj" (compile once: 1) (dfa mode: 0) (jit mode: 1) | |
| 2017/07/14 18:33:28 [debug] 68727#950739: malloc: 00007FC5E3802400:4096 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: malloc: 00007FC5E3803400:4096 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: free: 00007FC5E3802400 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: free: 00007FC5E3803400 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 pcre JIT compiling result: 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua saving compiled regex (0 captures) into the cache (entries 1) | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 regex "^(?:[0-9]{1,3}\.){3}[0-9]{1,3}$" not matched on string "api.example.com" starting from 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 [lua] resolver.lua:231: lookup(): resolver query: api.example.com search: query: api.example.com. | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 [lua] dns_client.lua:39: init_resolvers(): initializing 3 nameservers | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua udp socket network address given directly | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua udp socket resolve retval handler | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 UDP socket 10 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 connect to 127.0.0.1:1953, fd:10 #2 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 kevent set event: 10: ft:-1 fl:0025 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 http cleanup add: 00007FC5E28026F0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua udp socket connect: 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 [lua] dns_client.lua:48: init_resolvers(): nameserver 127.0.0.1:1953 initialized | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua udp socket network address given directly | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua udp socket resolve retval handler | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 UDP socket 11 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 connect to 192.168.0.1:53, fd:11 #3 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 kevent set event: 11: ft:-1 fl:0025 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 http cleanup add: 00007FC5E28027A8 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua udp socket connect: 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 [lua] dns_client.lua:48: init_resolvers(): nameserver 192.168.0.1:53 initialized | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua udp socket network address given directly | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua udp socket resolve retval handler | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 UDP socket 12 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 connect to 192.168.0.1:53, fd:12 #4 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 kevent set event: 12: ft:-1 fl:0025 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 http cleanup add: 00007FC5E3800440 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua udp socket connect: 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 [lua] dns_client.lua:48: init_resolvers(): nameserver 192.168.0.1:53 initialized | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 [lua] dns_client.lua:57: query(): resolver query: api.example.com. nameserver: 127.0.0.1:1953 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 send: fd:10 33 of 33 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua udp socket calling receive() method | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua udp socket read timeout: 2900 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua udp socket receive buffer size: 4096 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua udp socket read data: waiting: 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 recv: fd:10 -1 of 4096 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 recv() not ready (35: Resource temporarily unavailable) | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua udp recv returned -2 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 event timer add: 10: 2900:1500050011769 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua resume returned 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua thread yielded | |
| 2017/07/14 18:33:28 [debug] 68727#950739: timer delta: 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: worker cycle | |
| 2017/07/14 18:33:28 [debug] 68727#950739: kevent timer: 2900, changes: 3 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: kevent events: 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: kevent: 10: ft:-1 fl:0025 ff:00000000 d:64 ud:00007FC5E300BD38 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua udp socket handler for "/?", wev 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua udp socket read handler | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 event timer del: 10: 1500050011769 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua udp socket read data: waiting: 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 recv: fd:10 64 of 4096 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua udp recv returned 64 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua udp socket waking up the current request | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 access phase: 13 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua access handler, uri:"/" c:1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua udp operation done, resuming lua thread | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua udp socket calling prepare retvals handler 000000010F4DCF0E, u:000000000F97FE50 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua udp socket receive return value handler | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua run thread, top:0 c:1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 [lua] resolver.lua:240: lookup(): resolver query: api.example.com finished with 1 answers | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 [lua] cache.lua:70: store(): resolver cache write api.example.com with TLL 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: http lua semaphore post: 000000000F4420B0, n: 1, resources: 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 [lua] resolver.lua:287: get_servers(): query for api.example.com finished with 1 answers | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket pool get keepalive peer | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket keepalive connection pool not found | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket connect timeout: 60000 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket network address given directly | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket resolve retval handler | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 stream socket 13 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 connect to 127.0.0.1:1984, fd:13 #5 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 kevent set event: 13: ft:-1 fl:0025 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 kevent set event: 13: ft:-2 fl:0025 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 http cleanup add: 00007FC5E38004F0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket connect: -2 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 posix_memalign: 00007FC5E1E00290:128 @16 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 event timer add: 13: 60000:1500050068879 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua resume returned 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua thread yielded | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua run thread returned -2 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: timer delta: 10 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: worker cycle | |
| 2017/07/14 18:33:28 [debug] 68727#950739: kevent timer: 60000, changes: 2 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: kevent events: 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: kevent: 13: ft:-2 fl:0025 ff:00000000 d:146988 ud:00007FC5E300D870 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket handler for "/?", wev 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 event timer del: 13: 1500050068879 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket connected | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket waking up the current request (conn) | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 access phase: 13 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua access handler, uri:"/" c:1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp operation done, resuming lua thread | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket calling prepare retvals handler 000000010F4D431E, u:000000000F981A90 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua run thread, top:0 c:1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 [lua] http.lua:610: send_request(): | |
| GET /admin/api/services/proxy/configs/production.json?host=foo-apicast-staging.example.com&access_token=alaska-token HTTP/1.1 | |
| User-Agent: APIcast (+https://www.apicast.io) | |
| Connection: Keep-Alive | |
| Host: api.example.com:1984 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket send timeout: 60000 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua allocate new chainlink and new buf of size 228, cl:00007FC5E3800508 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua socket tcp_nodelay | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket send data | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 send: fd:13 228 of 228 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket sent all the data | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua allocate new chainlink and new buf of size 4096, cl:00007FC5E3800650 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 malloc: 00007FC5E2802800:4096 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 event timer add: 13: 60000:1500050068879 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua resume returned 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua thread yielded | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua run thread returned -2 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: timer delta: 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: worker cycle | |
| 2017/07/14 18:33:28 [debug] 68727#950739: kevent timer: 60000, changes: 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: kevent events: 2 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: kevent: 8: ft:-1 fl:0005 ff:00000000 d:1 ud:00007FC5E300BC68 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: accept on 0.0.0.0:1984, ready: 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: posix_memalign: 00007FC5E1E00310:512 @16 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 accept: 127.0.0.1:50814 fd:14 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 event timer add: 14: 60000:1500050068879 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 reusable connection: 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 kevent set event: 14: ft:-1 fl:0025 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: kevent: 13: ft:-2 fl:0025 ff:00000000 d:146988 ud:00007FC5E300D870 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket handler for "/?", wev 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket dummy handler | |
| 2017/07/14 18:33:28 [debug] 68727#950739: timer delta: 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: worker cycle | |
| 2017/07/14 18:33:28 [debug] 68727#950739: kevent timer: 60000, changes: 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: kevent events: 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: kevent: 14: ft:-1 fl:0025 ff:00000000 d:228 ud:00007FC5E300BED8 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http wait request handler | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 malloc: 00007FC5E2803800:1024 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 recv: eof:0, avail:228, err:0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 recv: fd:14 228 of 1024 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 reusable connection: 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 posix_memalign: 00007FC5E2803C00:4096 @16 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http process request line | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http request line: "GET /admin/api/services/proxy/configs/production.json?host=foo-apicast-staging.example.com&access_token=alaska-token HTTP/1.1" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http uri: "/admin/api/services/proxy/configs/production.json" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http args: "host=foo-apicast-staging.example.com&access_token=alaska-token" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http exten: "json" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 posix_memalign: 00007FC5E2804C00:4096 @16 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http process request header line | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http header: "User-Agent: APIcast (+https://www.apicast.io)" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http header: "Connection: Keep-Alive" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http header: "Host: api.example.com:1984" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http header done | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 event timer del: 14: 1500050068879 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 generic phase: 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 rewrite phase: 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 rewrite phase: 2 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 test location: "/admin/api/services/proxy/configs/sandbox.json" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 test location: "/admin/api/services/proxy/configs/production.json" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 using configuration "/admin/api/services/proxy/configs/production.json" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http cl:-1 max:1048576 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 rewrite phase: 4 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 rewrite phase: 5 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 post rewrite phase: 6 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 generic phase: 7 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 generic phase: 8 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 generic phase: 9 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 access phase: 10 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 access phase: 11 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 access phase: 12 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 access phase: 13 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 lua access handler, uri:"/admin/api/services/proxy/configs/production.json" c:1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 post access phase: 14 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 lua content handler, uri:"/admin/api/services/proxy/configs/production.json" c:1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 lua reset ctx | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 lua creating new thread | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http cleanup add: 00007FC5E2804A20 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 lua run thread, top:0 c:1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 lua allocate new chainlink and new buf of size 113, cl:00007FC5E2804A38 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 lua say response | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 lua capture header filter, uri "/admin/api/services/proxy/configs/production.json" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 HTTP/1.1 200 OK | |
| Server: openresty/1.11.2.3 | |
| Date: Fri, 14 Jul 2017 16:33:28 GMT | |
| Content-Type: text/plain | |
| Transfer-Encoding: chunked | |
| Connection: keep-alive | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 write new buf t:1 f:0 00007FC5E2804FE0, pos 00007FC5E2804FE0, size: 162 file: 0, size: 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http write filter: l:0 f:0 s:162 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http output filter "/admin/api/services/proxy/configs/production.json?host=foo-apicast-staging.example.com&access_token=alaska-token" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http copy filter: "/admin/api/services/proxy/configs/production.json?host=foo-apicast-staging.example.com&access_token=alaska-token" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 lua capture body filter, uri "/admin/api/services/proxy/configs/production.json" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http postpone filter "/admin/api/services/proxy/configs/production.json?host=foo-apicast-staging.example.com&access_token=alaska-token" 00007FC5E2804A38 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http chunk: 113 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 write old buf t:1 f:0 00007FC5E2804FE0, pos 00007FC5E2804FE0, size: 162 file: 0, size: 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 write new buf t:1 f:0 00007FC5E28050F8, pos 00007FC5E28050F8, size: 4 file: 0, size: 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 write new buf t:1 f:0 00007FC5E2804A98, pos 00007FC5E2804A98, size: 113 file: 0, size: 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 write new buf t:0 f:0 0000000000000000, pos 000000010F500B8C, size: 2 file: 0, size: 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http write filter: l:0 f:0 s:281 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http copy filter: 0 "/admin/api/services/proxy/configs/production.json?host=foo-apicast-staging.example.com&access_token=alaska-token" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 lua resume returned 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 lua light thread ended normally | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 lua deleting light thread | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http set discard body | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 lua sending last buf of the response body | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http output filter "/admin/api/services/proxy/configs/production.json?host=foo-apicast-staging.example.com&access_token=alaska-token" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http copy filter: "/admin/api/services/proxy/configs/production.json?host=foo-apicast-staging.example.com&access_token=alaska-token" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 lua capture body filter, uri "/admin/api/services/proxy/configs/production.json" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http postpone filter "/admin/api/services/proxy/configs/production.json?host=foo-apicast-staging.example.com&access_token=alaska-token" 00007FFF507FED50 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http chunk: 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 write old buf t:1 f:0 00007FC5E2804FE0, pos 00007FC5E2804FE0, size: 162 file: 0, size: 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 write old buf t:1 f:0 00007FC5E28050F8, pos 00007FC5E28050F8, size: 4 file: 0, size: 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 write old buf t:1 f:0 00007FC5E2804A98, pos 00007FC5E2804A98, size: 113 file: 0, size: 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 write old buf t:0 f:0 0000000000000000, pos 000000010F500B8C, size: 2 file: 0, size: 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 write new buf t:0 f:0 0000000000000000, pos 000000010F50128F, size: 5 file: 0, size: 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http write filter: l:1 f:0 s:286 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http write filter limit 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 writev: 286 of 286 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http write filter 0000000000000000 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http copy filter: 0 "/admin/api/services/proxy/configs/production.json?host=foo-apicast-staging.example.com&access_token=alaska-token" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http finalize request: 0, "/admin/api/services/proxy/configs/production.json?host=foo-apicast-staging.example.com&access_token=alaska-token" a:1, c:1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 set http keepalive handler | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http close request | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 lua request cleanup: forcible=0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 http log handler | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 free: 00007FC5E2803C00, unused: 8 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 free: 00007FC5E2804C00, unused: 2211 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 free: 00007FC5E2803800 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 hc free: 0000000000000000 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 hc busy: 0000000000000000 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 tcp_nodelay | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 reusable connection: 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *6 event timer add: 14: 68000:1500050076879 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: timer delta: 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: worker cycle | |
| 2017/07/14 18:33:28 [debug] 68727#950739: kevent timer: 60000, changes: 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: kevent events: 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: kevent: 13: ft:-1 fl:0025 ff:00000000 d:286 ud:00007FC5E300BE70 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket handler for "/?", wev 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read handler | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 event timer del: 13: 1500050068879 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read data: wait:1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket try to recv data 4096: "/?" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 recv: eof:0, avail:286, err:0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 recv: fd:13 286 of 4096 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket recv returned 286: "/?" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read line | |
| "017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read the final line part: "HTTP/1.1 200 OK | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive done: wait:1, eof:0, uri:"/?" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket waking up the current request (read) | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 access phase: 13 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua access handler, uri:"/" c:1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp operation done, resuming lua thread | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket calling prepare retvals handler 000000010F4D53BC, u:000000000F981A90 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua run thread, top:0 c:1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read line | |
| "017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read the final line part: "Server: openresty/1.11.2.3 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua regex cache miss for match regex "([^:\s]+):\s*(.+)" with options "jo" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua compiling match regex "([^:\s]+):\s*(.+)" with options "jo" (compile once: 1) (dfa mode: 0) (jit mode: 1) | |
| 2017/07/14 18:33:28 [debug] 68727#950739: malloc: 00007FC5E3803400:4096 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: malloc: 00007FC5E3802400:4096 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: free: 00007FC5E3803400 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: free: 00007FC5E3802400 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 pcre JIT compiling result: 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua saving compiled regex (2 captures) into the cache (entries 2) | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua regex cache miss for match regex "^\s*$" with options "jo" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua compiling match regex "^\s*$" with options "jo" (compile once: 1) (dfa mode: 0) (jit mode: 1) | |
| 2017/07/14 18:33:28 [debug] 68727#950739: malloc: 00007FC5E3802400:4096 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: malloc: 00007FC5E3803400:4096 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: free: 00007FC5E3802400 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: free: 00007FC5E3803400 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 pcre JIT compiling result: 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua saving compiled regex (0 captures) into the cache (entries 3) | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 regex "^\s*$" not matched on string "Server: openresty/1.11.2.3" starting from 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read line | |
| "017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read the final line part: "Date: Fri, 14 Jul 2017 16:33:28 GMT | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua regex cache hit for match regex "([^:\s]+):\s*(.+)" with options "jo" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua regex cache hit for match regex "^\s*$" with options "jo" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 regex "^\s*$" not matched on string "Date: Fri, 14 Jul 2017 16:33:28 GMT" starting from 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read line | |
| "017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read the final line part: "Content-Type: text/plain | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua regex cache hit for match regex "([^:\s]+):\s*(.+)" with options "jo" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua regex cache hit for match regex "^\s*$" with options "jo" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 regex "^\s*$" not matched on string "Content-Type: text/plain" starting from 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read line | |
| "017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read the final line part: "Transfer-Encoding: chunked | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua regex cache hit for match regex "([^:\s]+):\s*(.+)" with options "jo" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua regex cache hit for match regex "^\s*$" with options "jo" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 regex "^\s*$" not matched on string "Transfer-Encoding: chunked" starting from 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read line | |
| "017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read the final line part: "Connection: keep-alive | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua regex cache hit for match regex "([^:\s]+):\s*(.+)" with options "jo" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua regex cache hit for match regex "^\s*$" with options "jo" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 regex "^\s*$" not matched on string "Connection: keep-alive" starting from 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read line | |
| "017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read the final line part: " | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua regex cache hit for match regex "([^:\s]+):\s*(.+)" with options "jo" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 regex "([^:\s]+):\s*(.+)" not matched on string "" starting from 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua resume returned 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua thread yielded | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua coroutine: resume | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read line | |
| "017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read the final line part: "71 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read chunk 120 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua resume returned 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua thread yielded | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua coroutine: yield | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua resume returned 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua thread yielded | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua coroutine: resume | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read chunk 7 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read line | |
| "017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read the final line part: "0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket read chunk 2 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua resume returned 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua light thread ended normally | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua coroutine: lua user thread ended normally | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket set keepalive: saving connection 00007FC5E30085A0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket connection pool size: 30 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket keepalive create connection pool for key "127.0.0.1:1984" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket clear current socket connection | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua tcp socket keepalive timeout: 60000 ms | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 event timer add: 13: 60000:1500050068880 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua finalize socket | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua http cleanup free: 00007FC5E38004F0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua fetching existing ngx.ctx table for the current request | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua regex cache hit for match regex "^(?:(http[s]?):)?//([^:/\?]+)(?::(\d+))?([^\?]*)\??(.*)" with options "jo" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: from head of free queue, alloc semaphore: 000000000F442148 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: http lua semaphore new: 000000000F442148, resources: 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: http lua semaphore wait: 000000000F442148, timeout: 0, resources: 1, event posted: 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 [lua] cache.lua:118: fetch_answers(): resolver cache miss api.example.com | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 [lua] cache.lua:184: get(): resolver cache miss: api.example.com | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 [lua] resolver.lua:221: lookup(): resolver query: api.example.com | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua regex cache hit for match regex "^(?:[0-9]{1,3}\.){3}[0-9]{1,3}$" with options "oj" | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 regex "^(?:[0-9]{1,3}\.){3}[0-9]{1,3}$" not matched on string "api.example.com" starting from 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 [lua] resolver.lua:231: lookup(): resolver query: api.example.com search: query: api.example.com. | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 [lua] dns_client.lua:57: query(): resolver query: api.example.com. nameserver: 127.0.0.1:1953 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 send: fd:10 33 of 33 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua udp socket calling receive() method | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua udp socket read timeout: 2900 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua udp socket receive buffer size: 4096 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua udp socket read data: waiting: 0 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 recv: fd:10 -1 of 4096 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 recv() not ready (35: Resource temporarily unavailable) | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua udp recv returned -2 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 event timer add: 10: 2900:1500050011780 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua resume returned 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua thread yielded | |
| 2017/07/14 18:33:28 [debug] 68727#950739: *1 lua run thread returned -2 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: timer delta: 1 | |
| 2017/07/14 18:33:28 [debug] 68727#950739: worker cycle | |
| 2017/07/14 18:33:28 [debug] 68727#950739: kevent timer: 2900, changes: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent events: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: timer delta: 2902 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *1 event timer del: 10: 1500050011780 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *1 lua udp socket handler for "/?", wev 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *1 lua udp socket read handler | |
| 2017/07/14 18:33:31 [error] 68727#950739: *1 lua udp socket read timed out, client: 127.0.0.1, server: foo-apicast-staging.example.com, request: "GET / HTTP/1.1", host: "foo-apicast-staging.example.com" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *1 lua udp socket handle error | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *1 lua udp socket waking up the current request | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *1 access phase: 13 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *1 lua access handler, uri:"/" c:1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *1 lua udp operation done, resuming lua thread | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *1 lua udp socket calling prepare retvals handler 000000010F4DCF0E, u:000000000F97FE50 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *1 lua udp socket receive return value handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *1 lua udp socket error retval handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *1 lua run thread, top:0 c:1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *1 send: fd:10 33 of 33 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *1 lua udp socket calling receive() method | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *1 lua udp socket read timeout: 2900 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *1 lua udp socket receive buffer size: 4096 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *1 lua udp socket read data: waiting: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *1 recv: fd:10 -1 of 4096 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *1 recv() not ready (35: Resource temporarily unavailable) | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *1 lua udp recv returned -2 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *1 event timer add: 10: 2900:1500050014682 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *1 lua resume returned 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *1 lua thread yielded | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *1 lua run thread returned -2 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: worker cycle | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent timer: 2900, changes: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent events: 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent: 9: ft:-1 fl:8025 ff:00000000 d:0 ud:00007FC5E300BCD0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *1 http run request: "/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *1 http reading blocked | |
| 2017/07/14 18:33:31 [debug] 68727#950739: timer delta: 88 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: worker cycle | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent timer: 2812, changes: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent events: 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent: 8: ft:-1 fl:0005 ff:00000000 d:1 ud:00007FC5E300BC68 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: accept on 0.0.0.0:1984, ready: 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: posix_memalign: 00007FC5E1D00D40:512 @16 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 accept: 127.0.0.1:50815 fd:15 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 event timer add: 15: 60000:1500050071932 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 reusable connection: 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 kevent set event: 15: ft:-1 fl:0025 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: timer delta: 62 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: worker cycle | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent timer: 2750, changes: 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent events: 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent: 15: ft:-1 fl:0025 ff:00000000 d:76 ud:00007FC5E300BF40 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http wait request handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 malloc: 00007FC5E2002000:1024 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 recv: eof:0, avail:76, err:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 recv: fd:15 76 of 1024 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 reusable connection: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 posix_memalign: 00007FC5E2024400:4096 @16 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http process request line | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http request line: "GET / HTTP/1.1" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http uri: "/" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http args: "" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http exten: "" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 posix_memalign: 00007FC5E2019A00:4096 @16 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http process request header line | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http header: "Connection: close" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http header: "Host: foo-apicast-staging.example.com" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http header done | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 event timer del: 15: 1500050071932 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 generic phase: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 rewrite phase: 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 rewrite phase: 2 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 test location: "/" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 using configuration "/" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http cl:-1 max:31457280 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 rewrite phase: 4 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 rewrite phase: 5 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 post rewrite phase: 6 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 generic phase: 7 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 generic phase: 8 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 generic phase: 9 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 access phase: 10 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 access phase: 11 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 access phase: 12 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 access phase: 13 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua access handler, uri:"/" c:1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua creating new thread | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua reset ctx | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http cleanup add: 00007FC5E2025218 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua run thread, top:0 c:1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua create ngx.ctx table for the current request | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 add cleanup: 00007FC5E2025230 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: http lua semaphore wait: 000000000F442018, timeout: 0, resources: 1, event posted: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: http lua semaphore post: 000000000F442018, n: 1, resources: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua fetching existing ngx.ctx table for the current request | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 [lua] resolver.lua:141: new(): resolver search domains: | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua fetching existing ngx.ctx table for the current request | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua regex cache hit for match regex "^(?:(http[s]?):)?//([^:/\?]+)(?::(\d+))?([^\?]*)\??(.*)" with options "jo" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: http lua semaphore wait: 000000000F442148, timeout: 0, resources: 0, event posted: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 [lua] cache.lua:115: fetch_answers(): resolver cache stale api.example.com 1entries | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 [lua] cache.lua:186: get(): resolver cache hit: api.example.com 127.0.0.1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 [lua] resolver.lua:287: get_servers(): query for api.example.com finished with 1 answers | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket pool get keepalive peer | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket get keepalive peer: using connection 00007FC5E30085A0, fd:13 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 event timer del: 13: 1500050068880 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http cleanup add: 00007FC5E2025258 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 [lua] http.lua:610: send_request(): | |
| GET /admin/api/services/proxy/configs/production.json?host=foo-apicast-staging.example.com&access_token=alaska-token HTTP/1.1 | |
| User-Agent: APIcast (+https://www.apicast.io) | |
| Connection: Keep-Alive | |
| Host: api.example.com:1984 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket send timeout: 60000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua allocate new chainlink and new buf of size 228, cl:00007FC5E2025270 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket send data | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 send: fd:13 228 of 228 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket sent all the data | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua allocate new chainlink and new buf of size 4096, cl:00007FC5E20253B8 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 malloc: 00007FC5E201AA00:4096 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 event timer add: 13: 60000:1500050071932 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua resume returned 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua thread yielded | |
| 2017/07/14 18:33:31 [debug] 68727#950739: timer delta: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: worker cycle | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent timer: 2750, changes: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent events: 2 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent: 14: ft:-1 fl:0025 ff:00000000 d:228 ud:00007FC5E300BED8 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http keepalive handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 malloc: 00007FC5E201BA00:1024 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 recv: eof:0, avail:228, err:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 recv: fd:14 228 of 1024 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 reusable connection: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 posix_memalign: 00007FC5E2007400:4096 @16 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 event timer del: 14: 1500050076879 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http process request line | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http request line: "GET /admin/api/services/proxy/configs/production.json?host=foo-apicast-staging.example.com&access_token=alaska-token HTTP/1.1" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http uri: "/admin/api/services/proxy/configs/production.json" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http args: "host=foo-apicast-staging.example.com&access_token=alaska-token" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http exten: "json" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 posix_memalign: 00007FC5E2008400:4096 @16 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http process request header line | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http header: "User-Agent: APIcast (+https://www.apicast.io)" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http header: "Connection: Keep-Alive" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http header: "Host: api.example.com:1984" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http header done | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 generic phase: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 rewrite phase: 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 rewrite phase: 2 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 test location: "/admin/api/services/proxy/configs/sandbox.json" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 test location: "/admin/api/services/proxy/configs/production.json" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 using configuration "/admin/api/services/proxy/configs/production.json" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http cl:-1 max:1048576 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 rewrite phase: 4 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 rewrite phase: 5 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 post rewrite phase: 6 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 generic phase: 7 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 generic phase: 8 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 generic phase: 9 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 access phase: 10 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 access phase: 11 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 access phase: 12 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 access phase: 13 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 lua access handler, uri:"/admin/api/services/proxy/configs/production.json" c:1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 post access phase: 14 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 lua content handler, uri:"/admin/api/services/proxy/configs/production.json" c:1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 lua reset ctx | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 lua creating new thread | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http cleanup add: 00007FC5E2008220 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 lua run thread, top:0 c:1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 lua allocate new chainlink and new buf of size 113, cl:00007FC5E2008238 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 lua say response | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 lua capture header filter, uri "/admin/api/services/proxy/configs/production.json" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 HTTP/1.1 200 OK | |
| Server: openresty/1.11.2.3 | |
| Date: Fri, 14 Jul 2017 16:33:31 GMT | |
| Content-Type: text/plain | |
| Transfer-Encoding: chunked | |
| Connection: keep-alive | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 write new buf t:1 f:0 00007FC5E20087E0, pos 00007FC5E20087E0, size: 162 file: 0, size: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http write filter: l:0 f:0 s:162 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http output filter "/admin/api/services/proxy/configs/production.json?host=foo-apicast-staging.example.com&access_token=alaska-token" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http copy filter: "/admin/api/services/proxy/configs/production.json?host=foo-apicast-staging.example.com&access_token=alaska-token" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 lua capture body filter, uri "/admin/api/services/proxy/configs/production.json" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http postpone filter "/admin/api/services/proxy/configs/production.json?host=foo-apicast-staging.example.com&access_token=alaska-token" 00007FC5E2008238 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http chunk: 113 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 write old buf t:1 f:0 00007FC5E20087E0, pos 00007FC5E20087E0, size: 162 file: 0, size: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 write new buf t:1 f:0 00007FC5E20088F8, pos 00007FC5E20088F8, size: 4 file: 0, size: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 write new buf t:1 f:0 00007FC5E2008298, pos 00007FC5E2008298, size: 113 file: 0, size: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 write new buf t:0 f:0 0000000000000000, pos 000000010F500B8C, size: 2 file: 0, size: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http write filter: l:0 f:0 s:281 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http copy filter: 0 "/admin/api/services/proxy/configs/production.json?host=foo-apicast-staging.example.com&access_token=alaska-token" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 lua resume returned 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 lua light thread ended normally | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 lua deleting light thread | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http set discard body | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 lua sending last buf of the response body | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http output filter "/admin/api/services/proxy/configs/production.json?host=foo-apicast-staging.example.com&access_token=alaska-token" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http copy filter: "/admin/api/services/proxy/configs/production.json?host=foo-apicast-staging.example.com&access_token=alaska-token" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 lua capture body filter, uri "/admin/api/services/proxy/configs/production.json" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http postpone filter "/admin/api/services/proxy/configs/production.json?host=foo-apicast-staging.example.com&access_token=alaska-token" 00007FFF507FED50 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http chunk: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 write old buf t:1 f:0 00007FC5E20087E0, pos 00007FC5E20087E0, size: 162 file: 0, size: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 write old buf t:1 f:0 00007FC5E20088F8, pos 00007FC5E20088F8, size: 4 file: 0, size: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 write old buf t:1 f:0 00007FC5E2008298, pos 00007FC5E2008298, size: 113 file: 0, size: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 write old buf t:0 f:0 0000000000000000, pos 000000010F500B8C, size: 2 file: 0, size: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 write new buf t:0 f:0 0000000000000000, pos 000000010F50128F, size: 5 file: 0, size: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http write filter: l:1 f:0 s:286 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http write filter limit 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 writev: 286 of 286 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http write filter 0000000000000000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http copy filter: 0 "/admin/api/services/proxy/configs/production.json?host=foo-apicast-staging.example.com&access_token=alaska-token" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http finalize request: 0, "/admin/api/services/proxy/configs/production.json?host=foo-apicast-staging.example.com&access_token=alaska-token" a:1, c:1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 set http keepalive handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http close request | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 lua request cleanup: forcible=0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http log handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 free: 00007FC5E2007400, unused: 8 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 free: 00007FC5E2008400, unused: 2211 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 free: 00007FC5E201BA00 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 hc free: 0000000000000000 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 hc busy: 0000000000000000 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 reusable connection: 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 event timer add: 14: 68000:1500050079933 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent: 13: ft:-2 fl:0025 ff:00000000 d:146988 ud:00007FC5E300D870 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket handler for "/?", wev 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket dummy handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: timer delta: 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: worker cycle | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent timer: 2749, changes: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent events: 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent: 13: ft:-1 fl:0025 ff:00000000 d:286 ud:00007FC5E300BE70 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket handler for "/?", wev 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 event timer del: 13: 1500050071932 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read data: wait:1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket try to recv data 4096: "/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 recv: eof:0, avail:286, err:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 recv: fd:13 286 of 4096 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket recv returned 286: "/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read line | |
| "017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read the final line part: "HTTP/1.1 200 OK | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done: wait:1, eof:0, uri:"/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket waking up the current request (read) | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 access phase: 13 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua access handler, uri:"/" c:1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp operation done, resuming lua thread | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket calling prepare retvals handler 000000010F4D53BC, u:000000000F98B560 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua run thread, top:0 c:1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read line | |
| "017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read the final line part: "Server: openresty/1.11.2.3 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua regex cache hit for match regex "([^:\s]+):\s*(.+)" with options "jo" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua regex cache hit for match regex "^\s*$" with options "jo" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 regex "^\s*$" not matched on string "Server: openresty/1.11.2.3" starting from 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read line | |
| "017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read the final line part: "Date: Fri, 14 Jul 2017 16:33:31 GMT | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua regex cache hit for match regex "([^:\s]+):\s*(.+)" with options "jo" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua regex cache hit for match regex "^\s*$" with options "jo" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 regex "^\s*$" not matched on string "Date: Fri, 14 Jul 2017 16:33:31 GMT" starting from 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read line | |
| "017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read the final line part: "Content-Type: text/plain | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua regex cache hit for match regex "([^:\s]+):\s*(.+)" with options "jo" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua regex cache hit for match regex "^\s*$" with options "jo" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 regex "^\s*$" not matched on string "Content-Type: text/plain" starting from 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read line | |
| "017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read the final line part: "Transfer-Encoding: chunked | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua regex cache hit for match regex "([^:\s]+):\s*(.+)" with options "jo" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua regex cache hit for match regex "^\s*$" with options "jo" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 regex "^\s*$" not matched on string "Transfer-Encoding: chunked" starting from 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read line | |
| "017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read the final line part: "Connection: keep-alive | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua regex cache hit for match regex "([^:\s]+):\s*(.+)" with options "jo" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua regex cache hit for match regex "^\s*$" with options "jo" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 regex "^\s*$" not matched on string "Connection: keep-alive" starting from 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read line | |
| "017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read the final line part: " | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua regex cache hit for match regex "([^:\s]+):\s*(.+)" with options "jo" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 regex "([^:\s]+):\s*(.+)" not matched on string "" starting from 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua resume returned 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua thread yielded | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua coroutine: resume | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read line | |
| "017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read the final line part: "71 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read chunk 120 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua resume returned 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua thread yielded | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua coroutine: yield | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua resume returned 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua thread yielded | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua coroutine: resume | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read chunk 7 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read line | |
| "017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read the final line part: "0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read chunk 2 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua resume returned 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua light thread ended normally | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua coroutine: lua user thread ended normally | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket set keepalive: saving connection 00007FC5E30085A0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket clear current socket connection | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket keepalive timeout: 60000 ms | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 event timer add: 13: 60000:1500050071933 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua finalize socket | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua http cleanup free: 00007FC5E2025258 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua fetching existing ngx.ctx table for the current request | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua regex cache hit for match regex "^(?:(http[s]?):)?//([^:/\?]+)(?::(\d+))?([^\?]*)\??(.*)" with options "jo" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: http lua semaphore wait: 000000000F442148, timeout: 0, resources: 0, event posted: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 [lua] cache.lua:115: fetch_answers(): resolver cache stale api.example.com 1entries | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 [lua] cache.lua:186: get(): resolver cache hit: api.example.com 127.0.0.1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 [lua] resolver.lua:287: get_servers(): query for api.example.com finished with 1 answers | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket pool get keepalive peer | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket get keepalive peer: using connection 00007FC5E30085A0, fd:13 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 event timer del: 13: 1500050071933 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua http cleanup reuse: 00007FC5E2025258 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 [lua] http.lua:610: send_request(): | |
| GET /admin/api/services/proxy/configs/sandbox.json?host=foo-apicast-staging.example.com&access_token=alaska-token HTTP/1.1 | |
| User-Agent: APIcast (+https://www.apicast.io) | |
| Connection: Keep-Alive | |
| Host: api.example.com:1984 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket send timeout: 60000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua reuse free buf memory 228 >= 225, cl:00007FC5E2025270, p:00007FC5E20252D0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket send data | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 send: fd:13 225 of 225 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket sent all the data | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua reuse free buf memory 4096 >= 4096, cl:00007FC5E20253B8, p:00007FC5E201AA00 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 event timer add: 13: 60000:1500050071933 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua resume returned 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua thread yielded | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua run thread returned -2 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: timer delta: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: worker cycle | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent timer: 2749, changes: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent events: 2 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent: 14: ft:-1 fl:0025 ff:00000000 d:225 ud:00007FC5E300BED8 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http keepalive handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 malloc: 00007FC5E201BA00:1024 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 recv: eof:0, avail:225, err:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 recv: fd:14 225 of 1024 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 reusable connection: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 posix_memalign: 00007FC5E2007400:4096 @16 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 event timer del: 14: 1500050079933 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http process request line | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http request line: "GET /admin/api/services/proxy/configs/sandbox.json?host=foo-apicast-staging.example.com&access_token=alaska-token HTTP/1.1" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http uri: "/admin/api/services/proxy/configs/sandbox.json" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http args: "host=foo-apicast-staging.example.com&access_token=alaska-token" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http exten: "json" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 posix_memalign: 00007FC5E2008400:4096 @16 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http process request header line | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http header: "User-Agent: APIcast (+https://www.apicast.io)" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http header: "Connection: Keep-Alive" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http header: "Host: api.example.com:1984" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http header done | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 generic phase: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 rewrite phase: 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 rewrite phase: 2 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 test location: "/admin/api/services/proxy/configs/sandbox.json" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 using configuration "/admin/api/services/proxy/configs/sandbox.json" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http cl:-1 max:1048576 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 rewrite phase: 4 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 rewrite phase: 5 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 post rewrite phase: 6 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 generic phase: 7 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 generic phase: 8 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 generic phase: 9 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 access phase: 10 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 access phase: 11 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 access phase: 12 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 access phase: 13 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 lua access handler, uri:"/admin/api/services/proxy/configs/sandbox.json" c:1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 post access phase: 14 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 lua content handler, uri:"/admin/api/services/proxy/configs/sandbox.json" c:1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 lua reset ctx | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 lua creating new thread | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http cleanup add: 00007FC5E2008220 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 lua run thread, top:0 c:1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 lua allocate new chainlink and new buf of size 118, cl:00007FC5E2008238 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 lua say response | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 lua capture header filter, uri "/admin/api/services/proxy/configs/sandbox.json" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 HTTP/1.1 200 OK | |
| Server: openresty/1.11.2.3 | |
| Date: Fri, 14 Jul 2017 16:33:31 GMT | |
| Content-Type: text/plain | |
| Transfer-Encoding: chunked | |
| Connection: keep-alive | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 write new buf t:1 f:0 00007FC5E20087E0, pos 00007FC5E20087E0, size: 162 file: 0, size: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http write filter: l:0 f:0 s:162 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http output filter "/admin/api/services/proxy/configs/sandbox.json?host=foo-apicast-staging.example.com&access_token=alaska-token" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http copy filter: "/admin/api/services/proxy/configs/sandbox.json?host=foo-apicast-staging.example.com&access_token=alaska-token" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 lua capture body filter, uri "/admin/api/services/proxy/configs/sandbox.json" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http postpone filter "/admin/api/services/proxy/configs/sandbox.json?host=foo-apicast-staging.example.com&access_token=alaska-token" 00007FC5E2008238 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http chunk: 118 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 write old buf t:1 f:0 00007FC5E20087E0, pos 00007FC5E20087E0, size: 162 file: 0, size: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 write new buf t:1 f:0 00007FC5E20088F8, pos 00007FC5E20088F8, size: 4 file: 0, size: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 write new buf t:1 f:0 00007FC5E2008298, pos 00007FC5E2008298, size: 118 file: 0, size: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 write new buf t:0 f:0 0000000000000000, pos 000000010F500B8C, size: 2 file: 0, size: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http write filter: l:0 f:0 s:286 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http copy filter: 0 "/admin/api/services/proxy/configs/sandbox.json?host=foo-apicast-staging.example.com&access_token=alaska-token" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 lua resume returned 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 lua light thread ended normally | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 lua deleting light thread | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http set discard body | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 lua sending last buf of the response body | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http output filter "/admin/api/services/proxy/configs/sandbox.json?host=foo-apicast-staging.example.com&access_token=alaska-token" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http copy filter: "/admin/api/services/proxy/configs/sandbox.json?host=foo-apicast-staging.example.com&access_token=alaska-token" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 lua capture body filter, uri "/admin/api/services/proxy/configs/sandbox.json" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http postpone filter "/admin/api/services/proxy/configs/sandbox.json?host=foo-apicast-staging.example.com&access_token=alaska-token" 00007FFF507FED50 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http chunk: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 write old buf t:1 f:0 00007FC5E20087E0, pos 00007FC5E20087E0, size: 162 file: 0, size: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 write old buf t:1 f:0 00007FC5E20088F8, pos 00007FC5E20088F8, size: 4 file: 0, size: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 write old buf t:1 f:0 00007FC5E2008298, pos 00007FC5E2008298, size: 118 file: 0, size: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 write old buf t:0 f:0 0000000000000000, pos 000000010F500B8C, size: 2 file: 0, size: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 write new buf t:0 f:0 0000000000000000, pos 000000010F50128F, size: 5 file: 0, size: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http write filter: l:1 f:0 s:291 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http write filter limit 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 writev: 291 of 291 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http write filter 0000000000000000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http copy filter: 0 "/admin/api/services/proxy/configs/sandbox.json?host=foo-apicast-staging.example.com&access_token=alaska-token" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http finalize request: 0, "/admin/api/services/proxy/configs/sandbox.json?host=foo-apicast-staging.example.com&access_token=alaska-token" a:1, c:1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 set http keepalive handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http close request | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 lua request cleanup: forcible=0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 http log handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 free: 00007FC5E2007400, unused: 8 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 free: 00007FC5E2008400, unused: 2214 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 free: 00007FC5E201BA00 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 hc free: 0000000000000000 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 hc busy: 0000000000000000 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 reusable connection: 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *6 event timer add: 14: 68000:1500050079934 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent: 13: ft:-2 fl:0025 ff:00000000 d:146988 ud:00007FC5E300D870 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket handler for "/?", wev 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket dummy handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: timer delta: 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: worker cycle | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent timer: 2748, changes: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent events: 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent: 13: ft:-1 fl:0025 ff:00000000 d:291 ud:00007FC5E300BE70 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket handler for "/?", wev 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 event timer del: 13: 1500050071933 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read data: wait:1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket try to recv data 4096: "/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 recv: eof:0, avail:291, err:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 recv: fd:13 291 of 4096 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket recv returned 291: "/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read line | |
| "017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read the final line part: "HTTP/1.1 200 OK | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done: wait:1, eof:0, uri:"/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket waking up the current request (read) | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 access phase: 13 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua access handler, uri:"/" c:1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp operation done, resuming lua thread | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket calling prepare retvals handler 000000010F4D53BC, u:000000000F98FB10 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua run thread, top:0 c:1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read line | |
| "017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read the final line part: "Server: openresty/1.11.2.3 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua regex cache hit for match regex "([^:\s]+):\s*(.+)" with options "jo" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua regex cache hit for match regex "^\s*$" with options "jo" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 regex "^\s*$" not matched on string "Server: openresty/1.11.2.3" starting from 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read line | |
| "017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read the final line part: "Date: Fri, 14 Jul 2017 16:33:31 GMT | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua regex cache hit for match regex "([^:\s]+):\s*(.+)" with options "jo" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua regex cache hit for match regex "^\s*$" with options "jo" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 regex "^\s*$" not matched on string "Date: Fri, 14 Jul 2017 16:33:31 GMT" starting from 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read line | |
| "017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read the final line part: "Content-Type: text/plain | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua regex cache hit for match regex "([^:\s]+):\s*(.+)" with options "jo" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua regex cache hit for match regex "^\s*$" with options "jo" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 regex "^\s*$" not matched on string "Content-Type: text/plain" starting from 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read line | |
| "017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read the final line part: "Transfer-Encoding: chunked | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua regex cache hit for match regex "([^:\s]+):\s*(.+)" with options "jo" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua regex cache hit for match regex "^\s*$" with options "jo" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 regex "^\s*$" not matched on string "Transfer-Encoding: chunked" starting from 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read line | |
| "017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read the final line part: "Connection: keep-alive | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua regex cache hit for match regex "([^:\s]+):\s*(.+)" with options "jo" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua regex cache hit for match regex "^\s*$" with options "jo" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 regex "^\s*$" not matched on string "Connection: keep-alive" starting from 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read line | |
| "017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read the final line part: " | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua regex cache hit for match regex "([^:\s]+):\s*(.+)" with options "jo" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 regex "([^:\s]+):\s*(.+)" not matched on string "" starting from 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua resume returned 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua thread yielded | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua coroutine: resume | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read line | |
| "017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read the final line part: "76 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read chunk 125 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua resume returned 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua thread yielded | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua coroutine: yield | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua resume returned 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua thread yielded | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua coroutine: resume | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read chunk 7 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read line | |
| "017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read the final line part: "0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket calling receive() method | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read timeout: 60000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read data: wait:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket read chunk 2 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done: wait:0, eof:0, uri:"/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive done in a single run | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket receive return value handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua resume returned 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua light thread ended normally | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua coroutine: lua user thread ended normally | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket set keepalive: saving connection 00007FC5E30085A0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket clear current socket connection | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua tcp socket keepalive timeout: 60000 ms | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 event timer add: 13: 60000:1500050071934 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua finalize socket | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua http cleanup free: 00007FC5E2025258 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: from head of free queue, alloc semaphore: 000000000F4421E0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: http lua semaphore new: 000000000F4421E0, resources: 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: http lua semaphore wait: 000000000F4421E0, timeout: 0, resources: 1, event posted: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 [lua] cache.lua:118: fetch_answers(): resolver cache miss apicast-staging | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 [lua] cache.lua:184: get(): resolver cache miss: apicast-staging | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 [lua] resolver.lua:221: lookup(): resolver query: apicast-staging | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua regex cache hit for match regex "^(?:[0-9]{1,3}\.){3}[0-9]{1,3}$" with options "oj" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 regex "^(?:[0-9]{1,3}\.){3}[0-9]{1,3}$" not matched on string "apicast-staging" starting from 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 [lua] resolver.lua:231: lookup(): resolver query: apicast-staging search: query: apicast-staging. | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 [lua] dns_client.lua:39: init_resolvers(): initializing 3 nameservers | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua udp socket network address given directly | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua udp socket resolve retval handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 UDP socket 16 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 connect to 127.0.0.1:1953, fd:16 #8 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 kevent set event: 16: ft:-1 fl:0025 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http cleanup add: 00007FC5E201A240 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua udp socket connect: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 [lua] dns_client.lua:48: init_resolvers(): nameserver 127.0.0.1:1953 initialized | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua udp socket network address given directly | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua udp socket resolve retval handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 UDP socket 17 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 connect to 192.168.0.1:53, fd:17 #9 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 kevent set event: 17: ft:-1 fl:0025 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http cleanup add: 00007FC5E201A2F8 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua udp socket connect: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 [lua] dns_client.lua:48: init_resolvers(): nameserver 192.168.0.1:53 initialized | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua udp socket network address given directly | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua udp socket resolve retval handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 UDP socket 18 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 connect to 192.168.0.1:53, fd:18 #10 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 kevent set event: 18: ft:-1 fl:0025 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http cleanup add: 00007FC5E201A3B0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua udp socket connect: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 [lua] dns_client.lua:48: init_resolvers(): nameserver 192.168.0.1:53 initialized | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 [lua] dns_client.lua:57: query(): resolver query: apicast-staging. nameserver: 127.0.0.1:1953 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 send: fd:16 33 of 33 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua udp socket calling receive() method | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua udp socket read timeout: 2900 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua udp socket receive buffer size: 4096 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua udp socket read data: waiting: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 recv: fd:16 -1 of 4096 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 recv() not ready (35: Resource temporarily unavailable) | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua udp recv returned -2 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 event timer add: 16: 2900:1500050014834 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua resume returned 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua thread yielded | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua run thread returned -2 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: timer delta: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: worker cycle | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent timer: 2748, changes: 3 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent events: 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent: 16: ft:-1 fl:0025 ff:00000000 d:64 ud:00007FC5E300BFA8 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua udp socket handler for "/?", wev 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua udp socket read handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 event timer del: 16: 1500050014834 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua udp socket read data: waiting: 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 recv: fd:16 64 of 4096 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua udp recv returned 64 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua udp socket waking up the current request | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 access phase: 13 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua access handler, uri:"/" c:1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua udp operation done, resuming lua thread | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua udp socket calling prepare retvals handler 000000010F4DCF0E, u:000000000F9821D8 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua udp socket receive return value handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua run thread, top:0 c:1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 [lua] resolver.lua:240: lookup(): resolver query: apicast-staging finished with 1 answers | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 [lua] cache.lua:70: store(): resolver cache write api.example.com with TLL 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: http lua semaphore post: 000000000F4421E0, n: 1, resources: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 [lua] resolver.lua:287: get_apicast_servers(): query for apicast-staging finished with 1 answers | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua fetching existing ngx.ctx table for the current request | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua resume returned 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua light thread ended normally | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua deleting light thread | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua run thread returned 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 post access phase: 14 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http script var: "http" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http script copy: "://wildcard" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 posix_memalign: 00007FC5E2007400:4096 @16 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http init upstream, client timer: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 kevent set event: 15: ft:-2 fl:0025 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http script copy: "Host: " | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http script var: "foo-apicast-staging.example.com" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http script copy: " | |
| " | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http script copy: "" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http script copy: "" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http script copy: "" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http script copy: "" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http proxy header: | |
| "GET / HTTP/1.1 | |
| Host: foo-apicast-staging.example.com | |
| " | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http cleanup add: 00007FC5E20075B8 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 init keepalive peer | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 get keepalive peer | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua balancer peer, tries: 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua reset ctx | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua fetching existing ngx.ctx table for the current request | |
| 2017/07/14 18:33:31 [info] 68727#950739: *7 [lua] balancer.lua:110: set_peer(): balancer set peer 127.0.0.1:1953 while connecting to upstream, client: 127.0.0.1, server: foo-apicast-staging.example.com, request: "GET / HTTP/1.1", host: "foo-apicast-staging.example.com" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 stream socket 19 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 connect to 127.0.0.1:1953, fd:19 #11 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 kevent set event: 19: ft:-1 fl:0025 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 kevent set event: 19: ft:-2 fl:0025 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http upstream connect: -2 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 posix_memalign: 00007FC5E1C23C50:128 @16 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 event timer add: 19: 60000:1500050071936 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http finalize request: -4, "/?" a:1, c:2 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http request count:2 blk:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: timer delta: 2 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: worker cycle | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent timer: 2746, changes: 3 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent events: 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent: 15: ft:-2 fl:0025 ff:00000000 d:146988 ud:00007FC5E300D940 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http run request: "/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http upstream check client, write event:1, "/" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: timer delta: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: worker cycle | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent timer: 2746, changes: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent events: 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent: 19: ft:-2 fl:0025 ff:00000000 d:146988 ud:00007FC5E300DAE0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http upstream request: "/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http upstream send request handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http upstream send request | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http upstream send request body | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 chain writer buf fl:1 s:57 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 chain writer in: 00007FC5E20076B8 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 writev: 57 of 57 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 chain writer out: 0000000000000000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 event timer del: 19: 1500050071936 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 event timer add: 19: 60000:1500050071936 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: timer delta: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: worker cycle | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent timer: 2746, changes: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent events: 2 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent: 7: ft:-1 fl:0005 ff:00000000 d:1 ud:00007FC5E300BC00 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: accept on 0.0.0.0:1953, ready: 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: posix_memalign: 00007FC5E1C23CD0:512 @16 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 accept: 127.0.0.1:50816 fd:20 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 event timer add: 20: 60000:1500050071936 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 reusable connection: 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 kevent set event: 20: ft:-1 fl:0025 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent: 19: ft:-2 fl:0025 ff:00000000 d:146988 ud:00007FC5E300DAE0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http upstream request: "/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http upstream dummy handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: timer delta: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: worker cycle | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent timer: 2746, changes: 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent events: 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent: 20: ft:-1 fl:0025 ff:00000000 d:57 ud:00007FC5E300C148 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 http wait request handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 malloc: 00007FC5E201BA00:1024 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 recv: eof:0, avail:57, err:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 recv: fd:20 57 of 1024 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 reusable connection: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 posix_memalign: 00007FC5E2008400:4096 @16 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 http process request line | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 http request line: "GET / HTTP/1.1" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 http uri: "/" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 http args: "" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 http exten: "" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 posix_memalign: 00007FC5E203EC00:4096 @16 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 http process request header line | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 http header: "Host: foo-apicast-staging.example.com" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 http header done | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 event timer del: 20: 1500050071936 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 generic phase: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 rewrite phase: 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 rewrite phase: 2 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 test location: "/" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 using configuration "/" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 http cl:-1 max:1048576 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 rewrite phase: 4 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 rewrite phase: 5 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 post rewrite phase: 6 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 generic phase: 7 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 generic phase: 8 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 generic phase: 9 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 access phase: 10 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 access phase: 11 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 access phase: 12 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 access phase: 13 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 lua access handler, uri:"/" c:1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 post access phase: 14 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 lua content handler, uri:"/" c:1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 lua reset ctx | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 lua creating new thread | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 http cleanup add: 00007FC5E2009210 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 lua run thread, top:0 c:1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 lua exit with code 200 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 lua resume returned 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 lua thread yielded | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 lua thread aborting request with status 200 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 lua request cleanup: forcible=0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 lua capture header filter, uri "/" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 HTTP/1.1 200 OK | |
| Server: openresty/1.11.2.3 | |
| Date: Fri, 14 Jul 2017 16:33:31 GMT | |
| Content-Type: text/plain | |
| Transfer-Encoding: chunked | |
| Connection: keep-alive | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 write new buf t:1 f:0 00007FC5E2009288, pos 00007FC5E2009288, size: 162 file: 0, size: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 http write filter: l:0 f:0 s:162 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 http set discard body | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 lua sending last buf of the response body | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 http output filter "/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 http copy filter: "/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 lua capture body filter, uri "/" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 http postpone filter "/?" 00007FFF507FED50 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 http chunk: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 write old buf t:1 f:0 00007FC5E2009288, pos 00007FC5E2009288, size: 162 file: 0, size: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 write new buf t:0 f:0 0000000000000000, pos 000000010F50128F, size: 5 file: 0, size: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 http write filter: l:1 f:0 s:167 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 http write filter limit 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 writev: 167 of 167 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 http write filter 0000000000000000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 http copy filter: 0 "/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 http finalize request: 0, "/?" a:1, c:1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 set http keepalive handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 http close request | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 http log handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 free: 00007FC5E2008400, unused: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 free: 00007FC5E203EC00, unused: 2874 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 free: 00007FC5E201BA00 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 hc free: 0000000000000000 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 hc busy: 0000000000000000 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 tcp_nodelay | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 reusable connection: 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *12 event timer add: 20: 68000:1500050079936 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: timer delta: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: worker cycle | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent timer: 2746, changes: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent events: 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent: 19: ft:-1 fl:0025 ff:00000000 d:167 ud:00007FC5E300C0E0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http upstream request: "/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http upstream process header | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 malloc: 00007FC5E2008400:4096 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 recv: eof:0, avail:167, err:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 recv: fd:19 167 of 4096 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http proxy status 200 "200 OK" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http proxy header: "Server: openresty/1.11.2.3" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http proxy header: "Date: Fri, 14 Jul 2017 16:33:31 GMT" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http proxy header: "Content-Type: text/plain" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http proxy header: "Transfer-Encoding: chunked" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http proxy header: "Connection: keep-alive" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http proxy header done | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua capture header filter, uri "/" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 HTTP/1.1 200 OK | |
| Server: openresty/1.11.2.3 | |
| Date: Fri, 14 Jul 2017 16:33:31 GMT | |
| Content-Type: text/plain | |
| Transfer-Encoding: chunked | |
| Connection: close | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 write new buf t:1 f:0 00007FC5E2007970, pos 00007FC5E2007970, size: 157 file: 0, size: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http write filter: l:0 f:0 s:157 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http cacheable: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http proxy filter init s:200 h:0 c:1 l:-1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http upstream process upstream | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 pipe read upstream: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 pipe preread: 5 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 pipe buf free s:0 t:1 f:0 00007FC5E2008400, pos 00007FC5E20084A2, size: 5 file: 0, size: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 pipe length: 3 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http chunked byte: 30 s:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http chunked byte: 0D s:1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http chunked byte: 0A s:8 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http chunked byte: 0D s:9 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http chunked byte: 0A s:10 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http proxy chunked state 0, length 3 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 pipe write downstream: 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 pipe write downstream done | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 event timer: 19, old: 1500050071936, new: 1500050071937 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http upstream exit: 0000000000000000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 finalize http upstream request: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 finalize http proxy request | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 free keepalive peer | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 free keepalive peer: saving connection 00007FC5E3008B40 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 event timer del: 19: 1500050071936 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua balancer free peer, tries: 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http upstream temp fd: -1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http output filter "/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http copy filter: "/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua capture body filter, uri "/" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http postpone filter "/?" 00007FFF507FEEA0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http chunk: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 write old buf t:1 f:0 00007FC5E2007970, pos 00007FC5E2007970, size: 157 file: 0, size: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 write new buf t:0 f:0 0000000000000000, pos 000000010F50128F, size: 5 file: 0, size: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http write filter: l:1 f:0 s:162 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http write filter limit 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 writev: 162 of 162 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http write filter 0000000000000000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http copy filter: 0 "/?" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http finalize request: 0, "/?" a:1, c:1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http request count:1 blk:0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http close request | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 cleanup lua udp socket upstream request: "/" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua finalize socket | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua close socket connection | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 reusable connection: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 cleanup lua udp socket upstream request: "/" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua finalize socket | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua close socket connection | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 reusable connection: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 cleanup lua udp socket upstream request: "/" | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua finalize socket | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua close socket connection | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 reusable connection: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 lua request cleanup: forcible=0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 http log handler | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 run cleanup: 00007FC5E2025230 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: lua release ngx.ctx at ref 2 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 free: 00007FC5E2008400 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 free: 00007FC5E201AA00 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 free: 00007FC5E2024400, unused: 2 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 free: 00007FC5E2019A00, unused: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 free: 00007FC5E2007400, unused: 1834 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 close http connection: 15 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 reusable connection: 0 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 free: 00007FC5E2002000 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: *7 free: 00007FC5E1D00D40, unused: 128 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: timer delta: 1 | |
| 2017/07/14 18:33:31 [debug] 68727#950739: worker cycle | |
| 2017/07/14 18:33:31 [debug] 68727#950739: kevent timer: 2745, changes: 0 | |
| t/001-wildcard-router.t .. Failed 2/3 subtests | |
| Test Summary Report | |
| ------------------- | |
| t/001-wildcard-router.t (Wstat: 0 Tests: 3 Failed: 2) | |
| Failed tests: 1-2 | |
| Parse errors: No plan found in TAP output | |
| Files=1, Tests=3, 4 wallclock secs ( 0.02 usr 0.01 sys + 0.15 cusr 0.06 csys = 0.24 CPU) | |
| Result: FAIL | |
| make: *** [prove] Error 1 | |
| ➜ wildcard-service git:(wildcard-test) ✗ |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment