2016/11/15 19:11:23 [debug] 30741#30741: *251 post event 00006EFC4C5081F0 2016/11/15 19:11:23 [debug] 30741#30741: *251 post event 00006EFC4C2071F0 2016/11/15 19:11:23 [debug] 30741#30741: *251 delete posted event 00006EFC4C5081F0 2016/11/15 19:11:23 [debug] 30741#30741: *251 http run request: "/appname/socket/?EIO=3&transport=websocket&sid=UJyFqU73bEe42MVkAAAB" 2016/11/15 19:11:23 [debug] 30741#30741: *251 http upstream process upgraded, fu:0 2016/11/15 19:11:23 [debug] 30741#30741: *251 SSL_read: 9 2016/11/15 19:11:23 [debug] 30741#30741: *251 SSL_read: -1 2016/11/15 19:11:23 [debug] 30741#30741: *251 SSL_get_error: 2 2016/11/15 19:11:23 [debug] 30741#30741: *251 send: fd:14 9 of 9 2016/11/15 19:11:23 [debug] 30741#30741: *251 event timer del: 14: 1479237118051 2016/11/15 19:11:23 [debug] 30741#30741: *251 event timer add: 14: 60000:1479237143065 2016/11/15 19:11:23 [debug] 30741#30741: *251 delete posted event 00006EFC4C2071F0 2016/11/15 19:11:23 [debug] 30741#30741: *251 http run request: "/appname/socket/?EIO=3&transport=websocket&sid=UJyFqU73bEe42MVkAAAB" 2016/11/15 19:11:23 [debug] 30741#30741: *251 http upstream process upgraded, fu:1 2016/11/15 19:11:23 [debug] 30741#30741: *251 event timer: 14, old: 1479237143065, new: 1479237143065 2016/11/15 19:11:23 [debug] 30741#30741: *251 post event 00006EFC4C508250 2016/11/15 19:11:23 [debug] 30741#30741: *251 post event 00006EFC4C207250 2016/11/15 19:11:23 [debug] 30741#30741: *251 delete posted event 00006EFC4C508250 2016/11/15 19:11:23 [debug] 30741#30741: *251 http upstream request: "/appname/socket/?EIO=3&transport=websocket&sid=UJyFqU73bEe42MVkAAAB" 2016/11/15 19:11:23 [debug] 30741#30741: *251 http upstream process upgraded, fu:1 2016/11/15 19:11:23 [debug] 30741#30741: *251 recv: fd:14 3 of 4096 2016/11/15 19:11:23 [debug] 30741#30741: *251 SSL to write: 3 2016/11/15 19:11:23 [debug] 30741#30741: *251 SSL_write: 3 2016/11/15 19:11:23 [debug] 30741#30741: *251 recv: fd:14 -1 of 4096 2016/11/15 19:11:23 [debug] 30741#30741: *251 recv() not ready (11: Resource temporarily unavailable) 2016/11/15 19:11:23 [debug] 30741#30741: *251 event timer: 14, old: 1479237143065, new: 1479237143069 2016/11/15 19:11:23 [debug] 30741#30741: *251 delete posted event 00006EFC4C207250 2016/11/15 19:11:23 [debug] 30741#30741: *251 http upstream request: "/appname/socket/?EIO=3&transport=websocket&sid=UJyFqU73bEe42MVkAAAB" 2016/11/15 19:11:23 [debug] 30741#30741: *251 http upstream process upgraded, fu:0 2016/11/15 19:11:23 [debug] 30741#30741: *251 event timer: 14, old: 1479237143065, new: 1479237143069 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 idle handler 2016/11/15 19:11:26 [debug] 30743#30743: *162 reusable connection: 0 2016/11/15 19:11:26 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E03BC0:4096 @16 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 read handler 2016/11/15 19:11:26 [debug] 30743#30743: *162 SSL_read: 55 2016/11/15 19:11:26 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:26 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:26 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:26 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:26 [debug] 30743#30743: *162 SSL_read: -1 2016/11/15 19:11:26 [debug] 30743#30743: *162 SSL_get_error: 2 2016/11/15 19:11:26 [debug] 30743#30743: *162 process http2 frame type:1 f:24 l:46 sid:423 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 HEADERS frame sid:423 on 0 excl:0 weight:183 2016/11/15 19:11:26 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E61530:1024 @16 2016/11/15 19:11:26 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E120F0:4096 @16 2016/11/15 19:11:26 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E63480:4096 @16 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 get indexed header name: 3 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 get indexed header name: 92 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 get indexed header name: 7 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 hpack encoded string length: 4 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 hpack encoded string length: 13 2016/11/15 19:11:26 [debug] 30743#30743: *162 http uri: "/appname/v2/heartbeat" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http args: "" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http exten: "" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 get indexed header: 28 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 hpack encoded string length: 4 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 add header to hpack table: "content-length: 16175" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 hpack table account: 51 free:43 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 http header: "content-length: 16175" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 get indexed header name: 92 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 http header: "accept: application/json, text/plain, */*" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 get indexed header name: 71 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 http header: "origin: https://app3.mydomain.local" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 get indexed header name: 87 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 http header: "appname-csrf-token: YYY 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 get indexed header name: 90 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 http header: "user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.75 Safari/537.36" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 get indexed header name: 70 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 http header: "content-type: application/json;charset=UTF-8" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 get indexed header name: 68 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 http header: "accept-encoding: gzip, deflate, br" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 get indexed header name: 84 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 http header: "accept-language: en-US,en;q=0.8" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 get indexed header name: 83 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 get indexed header name: 82 2016/11/15 19:11:26 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E16F00:1024 @16 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 get indexed header name: 81 2016/11/15 19:11:26 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DC4930:1024 @16 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 get indexed header name: 80 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 get indexed header name: 86 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 http request line: "POST /appname/v2/heartbeat HTTP/2.0" 2016/11/15 19:11:26 [debug] 30743#30743: *162 generic phase: 0 2016/11/15 19:11:26 [debug] 30743#30743: *162 rewrite phase: 1 2016/11/15 19:11:26 [debug] 30743#30743: *162 test location: "^/widgets/$" 2016/11/15 19:11:26 [debug] 30743#30743: *162 test location: "/" 2016/11/15 19:11:26 [debug] 30743#30743: *162 test location: "docs/" 2016/11/15 19:11:26 [debug] 30743#30743: *162 test location: "appname/socket" 2016/11/15 19:11:26 [debug] 30743#30743: *162 test location: ~ "^/(index.html)?$" 2016/11/15 19:11:26 [debug] 30743#30743: *162 test location: ~ "^/login/?$" 2016/11/15 19:11:26 [debug] 30743#30743: *162 test location: ~ "^/(appname)" 2016/11/15 19:11:26 [debug] 30743#30743: *162 test location: ~ "/components/(.*)" 2016/11/15 19:11:26 [debug] 30743#30743: *162 test location: ~ "^/(auth|logout|status|widgetTypes|index.appname.html|login.appname.html|favicon.ico|(.*)\/vendor\/flags\/.*\.(?:jpg|png)|(.*)\/assets\/images\/company_logo.png)$" 2016/11/15 19:11:26 [debug] 30743#30743: *162 using configuration "/" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http cl:16175 max:1073741824 2016/11/15 19:11:26 [debug] 30743#30743: *162 rewrite phase: 3 2016/11/15 19:11:26 [debug] 30743#30743: *162 post rewrite phase: 4 2016/11/15 19:11:26 [debug] 30743#30743: *162 generic phase: 5 2016/11/15 19:11:26 [debug] 30743#30743: *162 generic phase: 6 2016/11/15 19:11:26 [debug] 30743#30743: *162 generic phase: 7 2016/11/15 19:11:26 [debug] 30743#30743: *162 access phase: 8 2016/11/15 19:11:26 [debug] 30743#30743: *162 access phase: 9 2016/11/15 19:11:26 [debug] 30743#30743: *162 access phase: 10 2016/11/15 19:11:26 [debug] 30743#30743: *162 auth request handler 2016/11/15 19:11:26 [debug] 30743#30743: *162 posix_memalign: 00000F0D34EB6570:4096 @16 2016/11/15 19:11:26 [debug] 30743#30743: *162 http subrequest "/authorize?" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http posted request: "/authorize?" 2016/11/15 19:11:26 [debug] 30743#30743: *162 rewrite phase: 1 2016/11/15 19:11:26 [debug] 30743#30743: *162 test location: "^/widgets/$" 2016/11/15 19:11:26 [debug] 30743#30743: *162 test location: "/" 2016/11/15 19:11:26 [debug] 30743#30743: *162 test location: "docs/" 2016/11/15 19:11:26 [debug] 30743#30743: *162 test location: "dashboard" 2016/11/15 19:11:26 [debug] 30743#30743: *162 test location: "authorize" 2016/11/15 19:11:26 [debug] 30743#30743: *162 using configuration "=/authorize" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http cl:16175 max:1073741824 2016/11/15 19:11:26 [debug] 30743#30743: *162 rewrite phase: 3 2016/11/15 19:11:26 [debug] 30743#30743: *162 post rewrite phase: 4 2016/11/15 19:11:26 [debug] 30743#30743: *162 generic phase: 5 2016/11/15 19:11:26 [debug] 30743#30743: *162 generic phase: 6 2016/11/15 19:11:26 [debug] 30743#30743: *162 generic phase: 7 2016/11/15 19:11:26 [debug] 30743#30743: *162 http init upstream, client timer: 0 2016/11/15 19:11:26 [debug] 30743#30743: *162 posix_memalign: 00000F0D34EB7580:4096 @16 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: "X-Real-IP: " 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script var: "192.168.123.11" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: "X-Forwarded-For: " 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script var: "192.168.123.11" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: "Host: " 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script var: "app3.mydomain.local" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: "X-NginX-Proxy: true " 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: "X-Client-S-DN: " 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script var: "XXX" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: "X-Client-Serial: " 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script var: "XXXX" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: "x-appname-uri: " 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script var: "/appname/v2/heartbeat" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: "x-appname-method: " 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script var: "POST" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: "Connection: close " 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: "" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: "" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header: "accept: application/json, text/plain, */*" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header: "origin: https://app3.mydomain.local" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header: "appname-csrf-token: YYY 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header: "user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.75 Safari/537.36" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header: "content-type: application/json;charset=UTF-8" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header: "accept-encoding: gzip, deflate, br" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header: "accept-language: en-US,en;q=0.8" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header: "cookie: XXX" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header: "GET /authorize HTTP/1.1 X-Real-IP: 192.168.123.11 X-Forwarded-For: 192.168.123.11 Host: app3.mydomain.local X-NginX-Proxy: true x-appname-uri: /appname/v2/heartbeat x-appname-method: POST Connection: close accept: application/json, text/plain, */* origin: https://app3.mydomain.local appname-csrf-token: YYY user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.75 Safari/537.36 content-type: application/json;charset=UTF-8 accept-encoding: gzip, deflate, br accept-language: en-US,en;q=0.8 2016/11/15 19:11:26 [debug] 30743#30743: *162 http cleanup add: 00000F0D34E64460 2016/11/15 19:11:26 [debug] 30743#30743: *162 get rr peer, try: 1 2016/11/15 19:11:26 [debug] 30743#30743: *162 stream socket 7 2016/11/15 19:11:26 [debug] 30743#30743: *162 epoll add connection: fd:7 ev:80002005 2016/11/15 19:11:26 [debug] 30743#30743: *162 connect to 127.0.0.1:8008, fd:7 #565 2016/11/15 19:11:26 [debug] 30743#30743: *162 http upstream connect: -2 2016/11/15 19:11:26 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBBA30:128 @16 2016/11/15 19:11:26 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237146566 2016/11/15 19:11:26 [debug] 30743#30743: *162 http finalize request: -4, "/authorize?" a:1, c:3 2016/11/15 19:11:26 [debug] 30743#30743: *162 http request count:3 blk:0 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AC047 end:00006EFC4F5AECFB 2016/11/15 19:11:26 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:423 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:26 [debug] 30743#30743: *162 malloc: 00000F0D34D89720:65536 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5ACB74 end:00006EFC4F5AECFB 2016/11/15 19:11:26 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:423 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AD6A1 end:00006EFC4F5AECFB 2016/11/15 19:11:26 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:423 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AE1CE end:00006EFC4F5AECFB 2016/11/15 19:11:26 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:423 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AECFB end:00006EFC4F5AECFB 2016/11/15 19:11:26 [debug] 30743#30743: *162 event timer del: 3: 1479237258370 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 write handler 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 read handler 2016/11/15 19:11:26 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:26 [debug] 30743#30743: *162 SSL_read: 1924 2016/11/15 19:11:26 [debug] 30743#30743: *162 SSL_read: -1 2016/11/15 19:11:26 [debug] 30743#30743: *162 SSL_get_error: 2 2016/11/15 19:11:26 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:423 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5ACB3D end:00006EFC4F5AD2C1 2016/11/15 19:11:26 [debug] 30743#30743: *162 process http2 frame type:0 f:1 l:1915 sid:423 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AD2C1 end:00006EFC4F5AD2C1 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 write handler 2016/11/15 19:11:26 [debug] 30743#30743: *162 http upstream request: "/authorize?" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http upstream send request handler 2016/11/15 19:11:26 [debug] 30743#30743: *162 http upstream send request 2016/11/15 19:11:26 [debug] 30743#30743: *162 http upstream send request body 2016/11/15 19:11:26 [debug] 30743#30743: *162 chain writer buf fl:1 s:2711 2016/11/15 19:11:26 [debug] 30743#30743: *162 chain writer in: 00000F0D34EB7550 2016/11/15 19:11:26 [debug] 30743#30743: *162 writev: 2711 of 2711 2016/11/15 19:11:26 [debug] 30743#30743: *162 chain writer out: 0000000000000000 2016/11/15 19:11:26 [debug] 30743#30743: *162 event timer del: 7: 1479237146566 2016/11/15 19:11:26 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237146567 2016/11/15 19:11:26 [debug] 30743#30743: *162 http upstream request: "/authorize?" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http upstream process header 2016/11/15 19:11:26 [debug] 30743#30743: *162 malloc: 00000F0D34DBC950:4096 2016/11/15 19:11:26 [debug] 30743#30743: *162 recv: fd:7 172 of 4096 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy status 200 "200 OK" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header: "X-Powered-By: Express" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header: "x-appname-origin: appname3" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header: "content-type: application/json" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header: "content-length: 0" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header: "Date: Tue, 15 Nov 2016 19:11:26 GMT" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header: "Connection: close" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header done 2016/11/15 19:11:26 [debug] 30743#30743: *162 lua capture header filter, uri "/authorize" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 header filter 2016/11/15 19:11:26 [debug] 30743#30743: *162 finalize http upstream request: 0 2016/11/15 19:11:26 [debug] 30743#30743: *162 finalize http proxy request 2016/11/15 19:11:26 [debug] 30743#30743: *162 free rr peer 1 0 2016/11/15 19:11:26 [debug] 30743#30743: *162 close http upstream connection: 7 2016/11/15 19:11:26 [debug] 30743#30743: *162 free: 00000F0D34DBBA30, unused: 48 2016/11/15 19:11:26 [debug] 30743#30743: *162 event timer del: 7: 1479237146567 2016/11/15 19:11:26 [debug] 30743#30743: *162 reusable connection: 0 2016/11/15 19:11:26 [debug] 30743#30743: *162 http finalize request: 0, "/authorize?" a:1, c:2 2016/11/15 19:11:26 [debug] 30743#30743: *162 auth request done s:200 2016/11/15 19:11:26 [debug] 30743#30743: *162 http wake parent request: "/appname/v2/heartbeat?" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http posted request: "/appname/v2/heartbeat?" 2016/11/15 19:11:26 [debug] 30743#30743: *162 access phase: 10 2016/11/15 19:11:26 [debug] 30743#30743: *162 auth request handler 2016/11/15 19:11:26 [debug] 30743#30743: *162 auth request set variables 2016/11/15 19:11:26 [debug] 30743#30743: *162 access phase: 11 2016/11/15 19:11:26 [debug] 30743#30743: *162 lua access handler, uri:"/appname/v2/heartbeat" c:1 2016/11/15 19:11:26 [debug] 30743#30743: *162 post access phase: 12 2016/11/15 19:11:26 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBD960:4096 @16 2016/11/15 19:11:26 [debug] 30743#30743: *162 http body new buf t:1 f:0 00000F0D34D89720, pos 00000F0D34D89720, size: 16175 file: 0, size: 0 2016/11/15 19:11:26 [debug] 30743#30743: *162 http init upstream, client timer: 0 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: "X-Real-IP: " 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script var: "192.168.123.11" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: "X-Forwarded-For: " 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script var: "192.168.123.11" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: "Host: " 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script var: "app3.mydomain.local" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: "X-NginX-Proxy: true " 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: "X-Client-S-DN: " 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script var: "XXX" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: "X-Client-Serial: " 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script var: "XXXX" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: "Connection: close " 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: "Content-Length: " 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script var: "16175" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: "" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http script copy: "" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header: "accept: application/json, text/plain, */*" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header: "origin: https://app3.mydomain.local" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header: "appname-csrf-token: YYY 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header: "user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.75 Safari/537.36" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header: "content-type: application/json;charset=UTF-8" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header: "accept-encoding: gzip, deflate, br" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header: "accept-language: en-US,en;q=0.8" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header: "cookie: XXX" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header: "POST /appname/v2/heartbeat HTTP/1.1 X-Real-IP: 192.168.123.11 X-Forwarded-For: 192.168.123.11 Host: app3.mydomain.local X-NginX-Proxy: true Connection: close Content-Length: 16175 accept: application/json, text/plain, */* origin: https://app3.mydomain.local appname-csrf-token: YYY user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.75 Safari/537.36 content-type: application/json;charset=UTF-8 accept-encoding: gzip, deflate, br accept-language: en-US,en;q=0.8 2016/11/15 19:11:26 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBE970:4096 @16 2016/11/15 19:11:26 [debug] 30743#30743: *162 http cleanup add: 00000F0D34DBE938 2016/11/15 19:11:26 [debug] 30743#30743: *162 get rr peer, try: 1 2016/11/15 19:11:26 [debug] 30743#30743: *162 stream socket 7 2016/11/15 19:11:26 [debug] 30743#30743: *162 epoll add connection: fd:7 ev:80002005 2016/11/15 19:11:26 [debug] 30743#30743: *162 connect to 182.168.128.69:8080, fd:7 #566 2016/11/15 19:11:26 [debug] 30743#30743: *162 http upstream connect: -2 2016/11/15 19:11:26 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBBA30:128 @16 2016/11/15 19:11:26 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237146611 2016/11/15 19:11:26 [debug] 30743#30743: *162 free: 00000F0D34D89720 2016/11/15 19:11:26 [debug] 30743#30743: *162 http finalize request: -4, "/appname/v2/heartbeat?" a:1, c:2 2016/11/15 19:11:26 [debug] 30743#30743: *162 http request count:2 blk:0 2016/11/15 19:11:26 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http upstream send request handler 2016/11/15 19:11:26 [debug] 30743#30743: *162 http upstream send request 2016/11/15 19:11:26 [debug] 30743#30743: *162 http upstream send request body 2016/11/15 19:11:26 [debug] 30743#30743: *162 chain writer buf fl:0 s:2690 2016/11/15 19:11:26 [debug] 30743#30743: *162 chain writer buf fl:1 s:16175 2016/11/15 19:11:26 [debug] 30743#30743: *162 chain writer in: 00000F0D34DBEA00 2016/11/15 19:11:26 [debug] 30743#30743: *162 writev: 18865 of 18865 2016/11/15 19:11:26 [debug] 30743#30743: *162 chain writer out: 0000000000000000 2016/11/15 19:11:26 [debug] 30743#30743: *162 event timer del: 7: 1479237146611 2016/11/15 19:11:26 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237146611 2016/11/15 19:11:26 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http upstream process header 2016/11/15 19:11:26 [debug] 30743#30743: *162 malloc: 00000F0D34D69D00:4096 2016/11/15 19:11:26 [debug] 30743#30743: *162 recv: fd:7 1056 of 4096 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy status 400 "400 Bad Request" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header: "Server: nginx" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header: "Date: Tue, 15 Nov 2016 19:11:24 GMT" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header: "Content-Type: text/html; charset=utf-8" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header: "Content-Length: 840" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header: "Connection: close" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header: "X-Powered-By: Express" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header: "X-Content-Type-Options: nosniff" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy header done 2016/11/15 19:11:26 [debug] 30743#30743: *162 lua capture header filter, uri "/appname/v2/heartbeat" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 header filter 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 output header: ":status: 400" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 output header: "server: nginx" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 output header: "date: Tue, 15 Nov 2016 19:11:26 GMT" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 output header: "content-type: text/html; charset=utf-8" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 output header: "content-length: 840" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 output header: "x-powered-by: Express" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 output header: "x-content-type-options: nosniff" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2:423 create HEADERS frame 00000F0D34DBEDA8: len:98 2016/11/15 19:11:26 [debug] 30743#30743: *162 http cleanup add: 00000F0D34DBEE90 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 frame out: 00000F0D34DBEDA8 sid:423 bl:1 len:98 2016/11/15 19:11:26 [debug] 30743#30743: *162 malloc: 00000F0D34D83A10:16384 2016/11/15 19:11:26 [debug] 30743#30743: *162 SSL buf copy: 9 2016/11/15 19:11:26 [debug] 30743#30743: *162 SSL buf copy: 98 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2:423 HEADERS frame 00000F0D34DBEDA8 was sent 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 frame sent: 00000F0D34DBEDA8 sid:423 bl:1 len:98 2016/11/15 19:11:26 [debug] 30743#30743: *162 http cacheable: 0 2016/11/15 19:11:26 [debug] 30743#30743: *162 http proxy filter init s:400 h:0 c:0 l:840 2016/11/15 19:11:26 [debug] 30743#30743: *162 http upstream process upstream 2016/11/15 19:11:26 [debug] 30743#30743: *162 pipe read upstream: 1 2016/11/15 19:11:26 [debug] 30743#30743: *162 pipe preread: 840 2016/11/15 19:11:26 [debug] 30743#30743: *162 readv: 1, last:3040 2016/11/15 19:11:26 [debug] 30743#30743: *162 pipe recv chain: 0 2016/11/15 19:11:26 [debug] 30743#30743: *162 pipe buf free s:0 t:1 f:0 00000F0D34D69D00, pos 00000F0D34D69DD8, size: 840 file: 0, size: 0 2016/11/15 19:11:26 [debug] 30743#30743: *162 pipe length: 840 2016/11/15 19:11:26 [debug] 30743#30743: *162 input buf #0 2016/11/15 19:11:26 [debug] 30743#30743: *162 pipe write downstream: 1 2016/11/15 19:11:26 [debug] 30743#30743: *162 pipe write downstream flush in 2016/11/15 19:11:26 [debug] 30743#30743: *162 http output filter "/appname/v2/heartbeat?" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http copy filter: "/appname/v2/heartbeat?" 2016/11/15 19:11:26 [debug] 30743#30743: *162 lua capture body filter, uri "/appname/v2/heartbeat" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http postpone filter "/appname/v2/heartbeat?" 00000F0D34DBEA00 2016/11/15 19:11:26 [debug] 30743#30743: *162 write new buf t:1 f:0 00000F0D34D69D00, pos 00000F0D34D69DD8, size: 840 file: 0, size: 0 2016/11/15 19:11:26 [debug] 30743#30743: *162 http write filter: l:0 f:0 s:840 2016/11/15 19:11:26 [debug] 30743#30743: *162 http copy filter: 0 "/appname/v2/heartbeat?" 2016/11/15 19:11:26 [debug] 30743#30743: *162 pipe write downstream done 2016/11/15 19:11:26 [debug] 30743#30743: *162 event timer: 7, old: 1479237146611, new: 1479237146644 2016/11/15 19:11:26 [debug] 30743#30743: *162 http upstream exit: 0000000000000000 2016/11/15 19:11:26 [debug] 30743#30743: *162 finalize http upstream request: 0 2016/11/15 19:11:26 [debug] 30743#30743: *162 finalize http proxy request 2016/11/15 19:11:26 [debug] 30743#30743: *162 free rr peer 1 0 2016/11/15 19:11:26 [debug] 30743#30743: *162 close http upstream connection: 7 2016/11/15 19:11:26 [debug] 30743#30743: *162 free: 00000F0D34DBBA30, unused: 48 2016/11/15 19:11:26 [debug] 30743#30743: *162 event timer del: 7: 1479237146611 2016/11/15 19:11:26 [debug] 30743#30743: *162 reusable connection: 0 2016/11/15 19:11:26 [debug] 30743#30743: *162 http upstream temp fd: -1 2016/11/15 19:11:26 [debug] 30743#30743: *162 http output filter "/appname/v2/heartbeat?" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http copy filter: "/appname/v2/heartbeat?" 2016/11/15 19:11:26 [debug] 30743#30743: *162 lua capture body filter, uri "/appname/v2/heartbeat" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http postpone filter "/appname/v2/heartbeat?" 00007A9E70E05A50 2016/11/15 19:11:26 [debug] 30743#30743: *162 write old buf t:1 f:0 00000F0D34D69D00, pos 00000F0D34D69DD8, size: 840 file: 0, size: 0 2016/11/15 19:11:26 [debug] 30743#30743: *162 write new buf t:0 f:0 0000000000000000, pos 0000000000000000, size: 0 file: 0, size: 0 2016/11/15 19:11:26 [debug] 30743#30743: *162 http write filter: l:1 f:0 s:840 2016/11/15 19:11:26 [debug] 30743#30743: *162 http write filter limit 0 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2:423 create DATA frame 00000F0D34DBEDA8: len:840 flags:1 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 frame out: 00000F0D34DBEDA8 sid:423 bl:0 len:840 2016/11/15 19:11:26 [debug] 30743#30743: *162 SSL buf copy: 9 2016/11/15 19:11:26 [debug] 30743#30743: *162 SSL buf copy: 840 2016/11/15 19:11:26 [debug] 30743#30743: *162 SSL to write: 956 2016/11/15 19:11:26 [debug] 30743#30743: *162 SSL_write: 956 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2:423 DATA frame 00000F0D34DBEDA8 was sent 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 frame sent: 00000F0D34DBEDA8 sid:423 bl:0 len:840 2016/11/15 19:11:26 [debug] 30743#30743: *162 http write filter 0000000000000000 2016/11/15 19:11:26 [debug] 30743#30743: *162 http copy filter: 0 "/appname/v2/heartbeat?" 2016/11/15 19:11:26 [debug] 30743#30743: *162 http finalize request: 0, "/appname/v2/heartbeat?" a:1, c:1 2016/11/15 19:11:26 [debug] 30743#30743: *162 http request count:1 blk:0 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 close stream 423, queued 0, processing 1 2016/11/15 19:11:26 [debug] 30743#30743: *162 http close request 2016/11/15 19:11:26 [debug] 30743#30743: *162 http log handler 2016/11/15 19:11:26 [debug] 30743#30743: *162 free: 00000F0D34DBC950 2016/11/15 19:11:26 [debug] 30743#30743: *162 free: 00000F0D34D69D00 2016/11/15 19:11:26 [debug] 30743#30743: *162 free: 00000F0D34E120F0, unused: 0 2016/11/15 19:11:26 [debug] 30743#30743: *162 free: 00000F0D34E63480, unused: 2 2016/11/15 19:11:26 [debug] 30743#30743: *162 free: 00000F0D34EB6570, unused: 0 2016/11/15 19:11:26 [debug] 30743#30743: *162 free: 00000F0D34EB7580, unused: 8 2016/11/15 19:11:26 [debug] 30743#30743: *162 free: 00000F0D34DBD960, unused: 0 2016/11/15 19:11:26 [debug] 30743#30743: *162 free: 00000F0D34DBE970, unused: 1926 2016/11/15 19:11:26 [debug] 30743#30743: *162 free: 00000F0D34E61530, unused: 162 2016/11/15 19:11:26 [debug] 30743#30743: *162 free: 00000F0D34E16F00, unused: 156 2016/11/15 19:11:26 [debug] 30743#30743: *162 free: 00000F0D34DC4930, unused: 111 2016/11/15 19:11:26 [debug] 30743#30743: *162 post event 00006EFC4C5081F0 2016/11/15 19:11:26 [debug] 30743#30743: *162 delete posted event 00006EFC4C5081F0 2016/11/15 19:11:26 [debug] 30743#30743: *162 http2 handle connection handler 2016/11/15 19:11:26 [debug] 30743#30743: *162 free: 00000F0D34E03BC0, unused: 3488 2016/11/15 19:11:26 [debug] 30743#30743: *162 free: 00000F0D34D83A10 2016/11/15 19:11:26 [debug] 30743#30743: *162 reusable connection: 1 2016/11/15 19:11:26 [debug] 30743#30743: *162 event timer add: 3: 180000:1479237266644 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 idle handler 2016/11/15 19:11:28 [debug] 30743#30743: *162 reusable connection: 0 2016/11/15 19:11:28 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E120F0:4096 @16 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 read handler 2016/11/15 19:11:28 [debug] 30743#30743: *162 SSL_read: 103 2016/11/15 19:11:28 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:28 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:28 [debug] 30743#30743: *162 SSL_read: -1 2016/11/15 19:11:28 [debug] 30743#30743: *162 SSL_get_error: 2 2016/11/15 19:11:28 [debug] 30743#30743: *162 process http2 frame type:1 f:24 l:94 sid:425 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 HEADERS frame sid:425 on 0 excl:0 weight:183 2016/11/15 19:11:28 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DC4930:1024 @16 2016/11/15 19:11:28 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E03BC0:4096 @16 2016/11/15 19:11:28 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E63480:4096 @16 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 get indexed header name: 3 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 get indexed header: 1 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 hpack encoded string length: 21 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 add header to hpack table: ":authority: app3.mydomain.local" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 hpack table account: 71 free:63 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 get indexed header name: 7 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 hpack encoded string length: 4 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 hpack encoded string length: 13 2016/11/15 19:11:28 [debug] 30743#30743: *162 http uri: "/appname/v2/heartbeat" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http args: "" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http exten: "" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 get indexed header: 28 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 hpack encoded string length: 4 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 add header to hpack table: "content-length: 26148" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 hpack table account: 51 free:63 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 http header: "content-length: 26148" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 get indexed header: 19 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 hpack encoded string length: 25 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 add header to hpack table: "accept: application/json, text/plain, */*" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 hpack table account: 71 free:12 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 http header: "accept: application/json, text/plain, */*" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 get indexed header name: 74 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 http header: "origin: https://app3.mydomain.local" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 get indexed header name: 90 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 http header: "appname-csrf-token: YYY 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 get indexed header name: 93 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 http header: "user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.75 Safari/537.36" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 get indexed header name: 73 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 http header: "content-type: application/json;charset=UTF-8" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 get indexed header name: 71 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 http header: "accept-encoding: gzip, deflate, br" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 get indexed header name: 87 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 http header: "accept-language: en-US,en;q=0.8" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 get indexed header name: 86 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 get indexed header name: 85 2016/11/15 19:11:28 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E16F00:1024 @16 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 get indexed header name: 84 2016/11/15 19:11:28 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E61530:1024 @16 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 get indexed header name: 83 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 get indexed header name: 89 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 http request line: "POST /appname/v2/heartbeat HTTP/2.0" 2016/11/15 19:11:28 [debug] 30743#30743: *162 generic phase: 0 2016/11/15 19:11:28 [debug] 30743#30743: *162 rewrite phase: 1 2016/11/15 19:11:28 [debug] 30743#30743: *162 test location: "^/widgets/$" 2016/11/15 19:11:28 [debug] 30743#30743: *162 test location: "/" 2016/11/15 19:11:28 [debug] 30743#30743: *162 test location: "docs/" 2016/11/15 19:11:28 [debug] 30743#30743: *162 test location: "appname/socket" 2016/11/15 19:11:28 [debug] 30743#30743: *162 test location: ~ "^/(index.html)?$" 2016/11/15 19:11:28 [debug] 30743#30743: *162 test location: ~ "^/login/?$" 2016/11/15 19:11:28 [debug] 30743#30743: *162 test location: ~ "^/(appname)" 2016/11/15 19:11:28 [debug] 30743#30743: *162 test location: ~ "/components/(.*)" 2016/11/15 19:11:28 [debug] 30743#30743: *162 test location: ~ "^/(auth|logout|status|widgetTypes|index.appname.html|login.appname.html|favicon.ico|(.*)\/vendor\/flags\/.*\.(?:jpg|png)|(.*)\/assets\/images\/company_logo.png)$" 2016/11/15 19:11:28 [debug] 30743#30743: *162 using configuration "/" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http cl:26148 max:1073741824 2016/11/15 19:11:28 [debug] 30743#30743: *162 rewrite phase: 3 2016/11/15 19:11:28 [debug] 30743#30743: *162 post rewrite phase: 4 2016/11/15 19:11:28 [debug] 30743#30743: *162 generic phase: 5 2016/11/15 19:11:28 [debug] 30743#30743: *162 generic phase: 6 2016/11/15 19:11:28 [debug] 30743#30743: *162 generic phase: 7 2016/11/15 19:11:28 [debug] 30743#30743: *162 access phase: 8 2016/11/15 19:11:28 [debug] 30743#30743: *162 access phase: 9 2016/11/15 19:11:28 [debug] 30743#30743: *162 access phase: 10 2016/11/15 19:11:28 [debug] 30743#30743: *162 auth request handler 2016/11/15 19:11:28 [debug] 30743#30743: *162 posix_memalign: 00000F0D34EB6570:4096 @16 2016/11/15 19:11:28 [debug] 30743#30743: *162 http subrequest "/authorize?" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http posted request: "/authorize?" 2016/11/15 19:11:28 [debug] 30743#30743: *162 rewrite phase: 1 2016/11/15 19:11:28 [debug] 30743#30743: *162 test location: "^/widgets/$" 2016/11/15 19:11:28 [debug] 30743#30743: *162 test location: "/" 2016/11/15 19:11:28 [debug] 30743#30743: *162 test location: "docs/" 2016/11/15 19:11:28 [debug] 30743#30743: *162 test location: "dashboard" 2016/11/15 19:11:28 [debug] 30743#30743: *162 test location: "authorize" 2016/11/15 19:11:28 [debug] 30743#30743: *162 using configuration "=/authorize" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http cl:26148 max:1073741824 2016/11/15 19:11:28 [debug] 30743#30743: *162 rewrite phase: 3 2016/11/15 19:11:28 [debug] 30743#30743: *162 post rewrite phase: 4 2016/11/15 19:11:28 [debug] 30743#30743: *162 generic phase: 5 2016/11/15 19:11:28 [debug] 30743#30743: *162 generic phase: 6 2016/11/15 19:11:28 [debug] 30743#30743: *162 generic phase: 7 2016/11/15 19:11:28 [debug] 30743#30743: *162 http init upstream, client timer: 0 2016/11/15 19:11:28 [debug] 30743#30743: *162 posix_memalign: 00000F0D34EB7580:4096 @16 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: "X-Real-IP: " 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script var: "192.168.123.11" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: "X-Forwarded-For: " 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script var: "192.168.123.11" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: "Host: " 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script var: "app3.mydomain.local" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: "X-NginX-Proxy: true " 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: "X-Client-S-DN: " 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script var: "XXX" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: "X-Client-Serial: " 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script var: "XXXX" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: "x-appname-uri: " 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script var: "/appname/v2/heartbeat" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: "x-appname-method: " 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script var: "POST" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: "Connection: close " 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: "" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: "" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header: "accept: application/json, text/plain, */*" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header: "origin: https://app3.mydomain.local" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header: "appname-csrf-token: YYY 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header: "user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.75 Safari/537.36" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header: "content-type: application/json;charset=UTF-8" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header: "accept-encoding: gzip, deflate, br" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header: "accept-language: en-US,en;q=0.8" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header: "cookie: XXX" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header: "GET /authorize HTTP/1.1 X-Real-IP: 192.168.123.11 X-Forwarded-For: 192.168.123.11 Host: app3.mydomain.local X-NginX-Proxy: true x-appname-uri: /appname/v2/heartbeat x-appname-method: POST Connection: close accept: application/json, text/plain, */* origin: https://app3.mydomain.local appname-csrf-token: YYY user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.75 Safari/537.36 content-type: application/json;charset=UTF-8 accept-encoding: gzip, deflate, br accept-language: en-US,en;q=0.8 2016/11/15 19:11:28 [debug] 30743#30743: *162 http cleanup add: 00000F0D34E64460 2016/11/15 19:11:28 [debug] 30743#30743: *162 get rr peer, try: 1 2016/11/15 19:11:28 [debug] 30743#30743: *162 stream socket 7 2016/11/15 19:11:28 [debug] 30743#30743: *162 epoll add connection: fd:7 ev:80002005 2016/11/15 19:11:28 [debug] 30743#30743: *162 connect to 127.0.0.1:8008, fd:7 #567 2016/11/15 19:11:28 [debug] 30743#30743: *162 http upstream connect: -2 2016/11/15 19:11:28 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBBA30:128 @16 2016/11/15 19:11:28 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237148378 2016/11/15 19:11:28 [debug] 30743#30743: *162 http finalize request: -4, "/authorize?" a:1, c:3 2016/11/15 19:11:28 [debug] 30743#30743: *162 http request count:3 blk:0 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AC077 end:00006EFC4F5AD6D1 2016/11/15 19:11:28 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:425 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:28 [debug] 30743#30743: *162 malloc: 00000F0D34D89720:65536 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5ACBA4 end:00006EFC4F5AD6D1 2016/11/15 19:11:28 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:425 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AD6D1 end:00006EFC4F5AD6D1 2016/11/15 19:11:28 [debug] 30743#30743: *162 event timer del: 3: 1479237266644 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 write handler 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 read handler 2016/11/15 19:11:28 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:28 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:28 [debug] 30743#30743: *162 SSL_read: -1 2016/11/15 19:11:28 [debug] 30743#30743: *162 SSL_get_error: 2 2016/11/15 19:11:28 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:425 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5ACB3D end:00006EFC4F5AD66A 2016/11/15 19:11:28 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:425 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AD66A end:00006EFC4F5AD66A 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 write handler 2016/11/15 19:11:28 [debug] 30743#30743: *162 http upstream request: "/authorize?" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http upstream send request handler 2016/11/15 19:11:28 [debug] 30743#30743: *162 http upstream send request 2016/11/15 19:11:28 [debug] 30743#30743: *162 http upstream send request body 2016/11/15 19:11:28 [debug] 30743#30743: *162 chain writer buf fl:1 s:2711 2016/11/15 19:11:28 [debug] 30743#30743: *162 chain writer in: 00000F0D34EB7550 2016/11/15 19:11:28 [debug] 30743#30743: *162 writev: 2711 of 2711 2016/11/15 19:11:28 [debug] 30743#30743: *162 chain writer out: 0000000000000000 2016/11/15 19:11:28 [debug] 30743#30743: *162 event timer del: 7: 1479237148378 2016/11/15 19:11:28 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237148379 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 read handler 2016/11/15 19:11:28 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:28 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:28 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:28 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:28 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:28 [debug] 30743#30743: *162 SSL_read: 489 2016/11/15 19:11:28 [debug] 30743#30743: *162 SSL_read: -1 2016/11/15 19:11:28 [debug] 30743#30743: *162 SSL_get_error: 2 2016/11/15 19:11:28 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:425 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5ACB3D end:00006EFC4F5AF9DA 2016/11/15 19:11:28 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:425 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AD66A end:00006EFC4F5AF9DA 2016/11/15 19:11:28 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:425 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AE197 end:00006EFC4F5AF9DA 2016/11/15 19:11:28 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:425 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AECC4 end:00006EFC4F5AF9DA 2016/11/15 19:11:28 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:425 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AF7F1 end:00006EFC4F5AF9DA 2016/11/15 19:11:28 [debug] 30743#30743: *162 process http2 frame type:0 f:1 l:480 sid:425 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AF9DA end:00006EFC4F5AF9DA 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 write handler 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 write handler 2016/11/15 19:11:28 [debug] 30743#30743: *162 http upstream request: "/authorize?" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http upstream process header 2016/11/15 19:11:28 [debug] 30743#30743: *162 malloc: 00000F0D34DBC950:4096 2016/11/15 19:11:28 [debug] 30743#30743: *162 recv: fd:7 172 of 4096 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy status 200 "200 OK" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header: "X-Powered-By: Express" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header: "x-appname-origin: appname3" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header: "content-type: application/json" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header: "content-length: 0" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header: "Date: Tue, 15 Nov 2016 19:11:28 GMT" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header: "Connection: close" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header done 2016/11/15 19:11:28 [debug] 30743#30743: *162 lua capture header filter, uri "/authorize" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 header filter 2016/11/15 19:11:28 [debug] 30743#30743: *162 finalize http upstream request: 0 2016/11/15 19:11:28 [debug] 30743#30743: *162 finalize http proxy request 2016/11/15 19:11:28 [debug] 30743#30743: *162 free rr peer 1 0 2016/11/15 19:11:28 [debug] 30743#30743: *162 close http upstream connection: 7 2016/11/15 19:11:28 [debug] 30743#30743: *162 free: 00000F0D34DBBA30, unused: 48 2016/11/15 19:11:28 [debug] 30743#30743: *162 event timer del: 7: 1479237148379 2016/11/15 19:11:28 [debug] 30743#30743: *162 reusable connection: 0 2016/11/15 19:11:28 [debug] 30743#30743: *162 http finalize request: 0, "/authorize?" a:1, c:2 2016/11/15 19:11:28 [debug] 30743#30743: *162 auth request done s:200 2016/11/15 19:11:28 [debug] 30743#30743: *162 http wake parent request: "/appname/v2/heartbeat?" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http posted request: "/appname/v2/heartbeat?" 2016/11/15 19:11:28 [debug] 30743#30743: *162 access phase: 10 2016/11/15 19:11:28 [debug] 30743#30743: *162 auth request handler 2016/11/15 19:11:28 [debug] 30743#30743: *162 auth request set variables 2016/11/15 19:11:28 [debug] 30743#30743: *162 access phase: 11 2016/11/15 19:11:28 [debug] 30743#30743: *162 lua access handler, uri:"/appname/v2/heartbeat" c:1 2016/11/15 19:11:28 [debug] 30743#30743: *162 post access phase: 12 2016/11/15 19:11:28 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBD960:4096 @16 2016/11/15 19:11:28 [debug] 30743#30743: *162 http body new buf t:1 f:0 00000F0D34D89720, pos 00000F0D34D89720, size: 26148 file: 0, size: 0 2016/11/15 19:11:28 [debug] 30743#30743: *162 http init upstream, client timer: 0 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: "X-Real-IP: " 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script var: "192.168.123.11" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: "X-Forwarded-For: " 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script var: "192.168.123.11" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: "Host: " 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script var: "app3.mydomain.local" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: "X-NginX-Proxy: true " 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: "X-Client-S-DN: " 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script var: "XXX" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: "X-Client-Serial: " 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script var: "XXXX" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: "Connection: close " 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: "Content-Length: " 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script var: "26148" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: "" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http script copy: "" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header: "accept: application/json, text/plain, */*" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header: "origin: https://app3.mydomain.local" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header: "appname-csrf-token: YYY 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header: "user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.75 Safari/537.36" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header: "content-type: application/json;charset=UTF-8" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header: "accept-encoding: gzip, deflate, br" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header: "accept-language: en-US,en;q=0.8" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header: "cookie: XXX" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header: "POST /appname/v2/heartbeat HTTP/1.1 X-Real-IP: 192.168.123.11 X-Forwarded-For: 192.168.123.11 Host: app3.mydomain.local X-NginX-Proxy: true Connection: close Content-Length: 26148 accept: application/json, text/plain, */* origin: https://app3.mydomain.local appname-csrf-token: YYY user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.75 Safari/537.36 content-type: application/json;charset=UTF-8 accept-encoding: gzip, deflate, br accept-language: en-US,en;q=0.8 2016/11/15 19:11:28 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBE970:4096 @16 2016/11/15 19:11:28 [debug] 30743#30743: *162 http cleanup add: 00000F0D34DBE938 2016/11/15 19:11:28 [debug] 30743#30743: *162 get rr peer, try: 1 2016/11/15 19:11:28 [debug] 30743#30743: *162 stream socket 7 2016/11/15 19:11:28 [debug] 30743#30743: *162 epoll add connection: fd:7 ev:80002005 2016/11/15 19:11:28 [debug] 30743#30743: *162 connect to 182.168.128.69:8080, fd:7 #568 2016/11/15 19:11:28 [debug] 30743#30743: *162 http upstream connect: -2 2016/11/15 19:11:28 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBBA30:128 @16 2016/11/15 19:11:28 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237148406 2016/11/15 19:11:28 [debug] 30743#30743: *162 free: 00000F0D34D89720 2016/11/15 19:11:28 [debug] 30743#30743: *162 http finalize request: -4, "/appname/v2/heartbeat?" a:1, c:2 2016/11/15 19:11:28 [debug] 30743#30743: *162 http request count:2 blk:0 2016/11/15 19:11:28 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http upstream send request handler 2016/11/15 19:11:28 [debug] 30743#30743: *162 http upstream send request 2016/11/15 19:11:28 [debug] 30743#30743: *162 http upstream send request body 2016/11/15 19:11:28 [debug] 30743#30743: *162 chain writer buf fl:0 s:2690 2016/11/15 19:11:28 [debug] 30743#30743: *162 chain writer buf fl:1 s:26148 2016/11/15 19:11:28 [debug] 30743#30743: *162 chain writer in: 00000F0D34DBEA00 2016/11/15 19:11:28 [debug] 30743#30743: *162 writev: 28838 of 28838 2016/11/15 19:11:28 [debug] 30743#30743: *162 chain writer out: 0000000000000000 2016/11/15 19:11:28 [debug] 30743#30743: *162 event timer del: 7: 1479237148406 2016/11/15 19:11:28 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237148406 2016/11/15 19:11:28 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http upstream process header 2016/11/15 19:11:28 [debug] 30743#30743: *162 malloc: 00000F0D34D69D00:4096 2016/11/15 19:11:28 [debug] 30743#30743: *162 recv: fd:7 1056 of 4096 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy status 400 "400 Bad Request" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header: "Server: nginx" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header: "Date: Tue, 15 Nov 2016 19:11:29 GMT" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header: "Content-Type: text/html; charset=utf-8" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header: "Content-Length: 840" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header: "Connection: close" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header: "X-Powered-By: Express" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header: "X-Content-Type-Options: nosniff" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy header done 2016/11/15 19:11:28 [debug] 30743#30743: *162 lua capture header filter, uri "/appname/v2/heartbeat" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 header filter 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 output header: ":status: 400" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 output header: "server: nginx" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 output header: "date: Tue, 15 Nov 2016 19:11:28 GMT" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 output header: "content-type: text/html; charset=utf-8" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 output header: "content-length: 840" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 output header: "x-powered-by: Express" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 output header: "x-content-type-options: nosniff" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2:425 create HEADERS frame 00000F0D34DBEDA8: len:98 2016/11/15 19:11:28 [debug] 30743#30743: *162 http cleanup add: 00000F0D34DBEE90 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 frame out: 00000F0D34DBEDA8 sid:425 bl:1 len:98 2016/11/15 19:11:28 [debug] 30743#30743: *162 malloc: 00000F0D34D83A10:16384 2016/11/15 19:11:28 [debug] 30743#30743: *162 SSL buf copy: 9 2016/11/15 19:11:28 [debug] 30743#30743: *162 SSL buf copy: 98 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2:425 HEADERS frame 00000F0D34DBEDA8 was sent 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 frame sent: 00000F0D34DBEDA8 sid:425 bl:1 len:98 2016/11/15 19:11:28 [debug] 30743#30743: *162 http cacheable: 0 2016/11/15 19:11:28 [debug] 30743#30743: *162 http proxy filter init s:400 h:0 c:0 l:840 2016/11/15 19:11:28 [debug] 30743#30743: *162 http upstream process upstream 2016/11/15 19:11:28 [debug] 30743#30743: *162 pipe read upstream: 1 2016/11/15 19:11:28 [debug] 30743#30743: *162 pipe preread: 840 2016/11/15 19:11:28 [debug] 30743#30743: *162 readv: 1, last:3040 2016/11/15 19:11:28 [debug] 30743#30743: *162 pipe recv chain: 0 2016/11/15 19:11:28 [debug] 30743#30743: *162 pipe buf free s:0 t:1 f:0 00000F0D34D69D00, pos 00000F0D34D69DD8, size: 840 file: 0, size: 0 2016/11/15 19:11:28 [debug] 30743#30743: *162 pipe length: 840 2016/11/15 19:11:28 [debug] 30743#30743: *162 input buf #0 2016/11/15 19:11:28 [debug] 30743#30743: *162 pipe write downstream: 1 2016/11/15 19:11:28 [debug] 30743#30743: *162 pipe write downstream flush in 2016/11/15 19:11:28 [debug] 30743#30743: *162 http output filter "/appname/v2/heartbeat?" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http copy filter: "/appname/v2/heartbeat?" 2016/11/15 19:11:28 [debug] 30743#30743: *162 lua capture body filter, uri "/appname/v2/heartbeat" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http postpone filter "/appname/v2/heartbeat?" 00000F0D34DBEA00 2016/11/15 19:11:28 [debug] 30743#30743: *162 write new buf t:1 f:0 00000F0D34D69D00, pos 00000F0D34D69DD8, size: 840 file: 0, size: 0 2016/11/15 19:11:28 [debug] 30743#30743: *162 http write filter: l:0 f:0 s:840 2016/11/15 19:11:28 [debug] 30743#30743: *162 http copy filter: 0 "/appname/v2/heartbeat?" 2016/11/15 19:11:28 [debug] 30743#30743: *162 pipe write downstream done 2016/11/15 19:11:28 [debug] 30743#30743: *162 event timer: 7, old: 1479237148406, new: 1479237148418 2016/11/15 19:11:28 [debug] 30743#30743: *162 http upstream exit: 0000000000000000 2016/11/15 19:11:28 [debug] 30743#30743: *162 finalize http upstream request: 0 2016/11/15 19:11:28 [debug] 30743#30743: *162 finalize http proxy request 2016/11/15 19:11:28 [debug] 30743#30743: *162 free rr peer 1 0 2016/11/15 19:11:28 [debug] 30743#30743: *162 close http upstream connection: 7 2016/11/15 19:11:28 [debug] 30743#30743: *162 free: 00000F0D34DBBA30, unused: 48 2016/11/15 19:11:28 [debug] 30743#30743: *162 event timer del: 7: 1479237148406 2016/11/15 19:11:28 [debug] 30743#30743: *162 reusable connection: 0 2016/11/15 19:11:28 [debug] 30743#30743: *162 http upstream temp fd: -1 2016/11/15 19:11:28 [debug] 30743#30743: *162 http output filter "/appname/v2/heartbeat?" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http copy filter: "/appname/v2/heartbeat?" 2016/11/15 19:11:28 [debug] 30743#30743: *162 lua capture body filter, uri "/appname/v2/heartbeat" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http postpone filter "/appname/v2/heartbeat?" 00007A9E70E05A50 2016/11/15 19:11:28 [debug] 30743#30743: *162 write old buf t:1 f:0 00000F0D34D69D00, pos 00000F0D34D69DD8, size: 840 file: 0, size: 0 2016/11/15 19:11:28 [debug] 30743#30743: *162 write new buf t:0 f:0 0000000000000000, pos 0000000000000000, size: 0 file: 0, size: 0 2016/11/15 19:11:28 [debug] 30743#30743: *162 http write filter: l:1 f:0 s:840 2016/11/15 19:11:28 [debug] 30743#30743: *162 http write filter limit 0 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2:425 create DATA frame 00000F0D34DBEDA8: len:840 flags:1 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 frame out: 00000F0D34DBEDA8 sid:425 bl:0 len:840 2016/11/15 19:11:28 [debug] 30743#30743: *162 SSL buf copy: 9 2016/11/15 19:11:28 [debug] 30743#30743: *162 SSL buf copy: 840 2016/11/15 19:11:28 [debug] 30743#30743: *162 SSL to write: 956 2016/11/15 19:11:28 [debug] 30743#30743: *162 SSL_write: 956 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2:425 DATA frame 00000F0D34DBEDA8 was sent 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 frame sent: 00000F0D34DBEDA8 sid:425 bl:0 len:840 2016/11/15 19:11:28 [debug] 30743#30743: *162 http write filter 0000000000000000 2016/11/15 19:11:28 [debug] 30743#30743: *162 http copy filter: 0 "/appname/v2/heartbeat?" 2016/11/15 19:11:28 [debug] 30743#30743: *162 http finalize request: 0, "/appname/v2/heartbeat?" a:1, c:1 2016/11/15 19:11:28 [debug] 30743#30743: *162 http request count:1 blk:0 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 close stream 425, queued 0, processing 1 2016/11/15 19:11:28 [debug] 30743#30743: *162 http close request 2016/11/15 19:11:28 [debug] 30743#30743: *162 http log handler 2016/11/15 19:11:28 [debug] 30743#30743: *162 free: 00000F0D34DBC950 2016/11/15 19:11:28 [debug] 30743#30743: *162 free: 00000F0D34D69D00 2016/11/15 19:11:28 [debug] 30743#30743: *162 free: 00000F0D34E03BC0, unused: 0 2016/11/15 19:11:28 [debug] 30743#30743: *162 free: 00000F0D34E63480, unused: 2 2016/11/15 19:11:28 [debug] 30743#30743: *162 free: 00000F0D34EB6570, unused: 0 2016/11/15 19:11:28 [debug] 30743#30743: *162 free: 00000F0D34EB7580, unused: 8 2016/11/15 19:11:28 [debug] 30743#30743: *162 free: 00000F0D34DBD960, unused: 0 2016/11/15 19:11:28 [debug] 30743#30743: *162 free: 00000F0D34DBE970, unused: 1926 2016/11/15 19:11:28 [debug] 30743#30743: *162 free: 00000F0D34DC4930, unused: 169 2016/11/15 19:11:28 [debug] 30743#30743: *162 free: 00000F0D34E16F00, unused: 156 2016/11/15 19:11:28 [debug] 30743#30743: *162 free: 00000F0D34E61530, unused: 111 2016/11/15 19:11:28 [debug] 30743#30743: *162 post event 00006EFC4C5081F0 2016/11/15 19:11:28 [debug] 30743#30743: *162 delete posted event 00006EFC4C5081F0 2016/11/15 19:11:28 [debug] 30743#30743: *162 http2 handle connection handler 2016/11/15 19:11:28 [debug] 30743#30743: *162 free: 00000F0D34E120F0, unused: 3488 2016/11/15 19:11:28 [debug] 30743#30743: *162 free: 00000F0D34D83A10 2016/11/15 19:11:28 [debug] 30743#30743: *162 reusable connection: 1 2016/11/15 19:11:28 [debug] 30743#30743: *162 event timer add: 3: 180000:1479237268418 2016/11/15 19:11:31 [debug] 30741#30741: *300 post event 00006EFC4C5082B0 2016/11/15 19:11:31 [debug] 30741#30741: *300 post event 00006EFC4C2072B0 2016/11/15 19:11:31 [debug] 30741#30741: *300 delete posted event 00006EFC4C5082B0 2016/11/15 19:11:31 [debug] 30741#30741: *300 http run request: "/appname/socket/?EIO=3&transport=websocket&sid=fJvr3YafvdqAy4F3AAAC" 2016/11/15 19:11:31 [debug] 30741#30741: *300 http upstream process upgraded, fu:0 2016/11/15 19:11:31 [debug] 30741#30741: *300 SSL_read: 9 2016/11/15 19:11:31 [debug] 30741#30741: *300 SSL_read: -1 2016/11/15 19:11:31 [debug] 30741#30741: *300 SSL_get_error: 2 2016/11/15 19:11:31 [debug] 30741#30741: *300 send: fd:16 9 of 9 2016/11/15 19:11:31 [debug] 30741#30741: *300 event timer del: 16: 1479237126558 2016/11/15 19:11:31 [debug] 30741#30741: *300 event timer add: 16: 60000:1479237151562 2016/11/15 19:11:31 [debug] 30741#30741: *300 delete posted event 00006EFC4C2072B0 2016/11/15 19:11:31 [debug] 30741#30741: *300 http run request: "/appname/socket/?EIO=3&transport=websocket&sid=fJvr3YafvdqAy4F3AAAC" 2016/11/15 19:11:31 [debug] 30741#30741: *300 http upstream process upgraded, fu:1 2016/11/15 19:11:31 [debug] 30741#30741: *300 event timer: 16, old: 1479237151562, new: 1479237151562 2016/11/15 19:11:31 [debug] 30741#30741: *300 post event 00006EFC4C508310 2016/11/15 19:11:31 [debug] 30741#30741: *300 post event 00006EFC4C207310 2016/11/15 19:11:31 [debug] 30741#30741: *300 delete posted event 00006EFC4C508310 2016/11/15 19:11:31 [debug] 30741#30741: *300 http upstream request: "/appname/socket/?EIO=3&transport=websocket&sid=fJvr3YafvdqAy4F3AAAC" 2016/11/15 19:11:31 [debug] 30741#30741: *300 http upstream process upgraded, fu:1 2016/11/15 19:11:31 [debug] 30741#30741: *300 recv: fd:16 3 of 4096 2016/11/15 19:11:31 [debug] 30741#30741: *300 SSL to write: 3 2016/11/15 19:11:31 [debug] 30741#30741: *300 SSL_write: 3 2016/11/15 19:11:31 [debug] 30741#30741: *300 recv: fd:16 -1 of 4096 2016/11/15 19:11:31 [debug] 30741#30741: *300 recv() not ready (11: Resource temporarily unavailable) 2016/11/15 19:11:31 [debug] 30741#30741: *300 event timer: 16, old: 1479237151562, new: 1479237151564 2016/11/15 19:11:31 [debug] 30741#30741: *300 delete posted event 00006EFC4C207310 2016/11/15 19:11:31 [debug] 30741#30741: *300 http upstream request: "/appname/socket/?EIO=3&transport=websocket&sid=fJvr3YafvdqAy4F3AAAC" 2016/11/15 19:11:31 [debug] 30741#30741: *300 http upstream process upgraded, fu:0 2016/11/15 19:11:31 [debug] 30741#30741: *300 event timer: 16, old: 1479237151562, new: 1479237151564 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 idle handler 2016/11/15 19:11:38 [debug] 30743#30743: *162 reusable connection: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E03BC0:4096 @16 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 read handler 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL_read: 55 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL_read: 17 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL_read: -1 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL_get_error: 2 2016/11/15 19:11:38 [debug] 30743#30743: *162 process http2 frame type:1 f:24 l:46 sid:427 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 HEADERS frame sid:427 on 0 excl:0 weight:183 2016/11/15 19:11:38 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E61530:1024 @16 2016/11/15 19:11:38 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E120F0:4096 @16 2016/11/15 19:11:38 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E63480:4096 @16 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header name: 3 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header name: 64 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header name: 7 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 hpack encoded string length: 4 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 hpack encoded string length: 13 2016/11/15 19:11:38 [debug] 30743#30743: *162 http uri: "/appname/v2/heartbeat" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http args: "" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http exten: "" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header: 28 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 hpack encoded string length: 4 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 add header to hpack table: "content-length: 26358" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 hpack table account: 51 free:132 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 http header: "content-length: 26358" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header name: 63 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 http header: "accept: application/json, text/plain, */*" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header name: 75 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 http header: "origin: https://app3.mydomain.local" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header name: 91 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 http header: "appname-csrf-token: YYY 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header name: 94 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 http header: "user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.75 Safari/537.36" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header name: 74 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 http header: "content-type: application/json;charset=UTF-8" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header name: 72 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 http header: "accept-encoding: gzip, deflate, br" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header name: 88 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 http header: "accept-language: en-US,en;q=0.8" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header name: 87 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header name: 86 2016/11/15 19:11:38 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E16F00:1024 @16 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header name: 85 2016/11/15 19:11:38 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DC4930:1024 @16 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header name: 84 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header name: 90 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 http request line: "POST /appname/v2/heartbeat HTTP/2.0" 2016/11/15 19:11:38 [debug] 30743#30743: *162 generic phase: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 rewrite phase: 1 2016/11/15 19:11:38 [debug] 30743#30743: *162 test location: "^/widgets/$" 2016/11/15 19:11:38 [debug] 30743#30743: *162 test location: "/" 2016/11/15 19:11:38 [debug] 30743#30743: *162 test location: "docs/" 2016/11/15 19:11:38 [debug] 30743#30743: *162 test location: "appname/socket" 2016/11/15 19:11:38 [debug] 30743#30743: *162 test location: ~ "^/(index.html)?$" 2016/11/15 19:11:38 [debug] 30743#30743: *162 test location: ~ "^/login/?$" 2016/11/15 19:11:38 [debug] 30743#30743: *162 test location: ~ "^/(appname)" 2016/11/15 19:11:38 [debug] 30743#30743: *162 test location: ~ "/components/(.*)" 2016/11/15 19:11:38 [debug] 30743#30743: *162 test location: ~ "^/(auth|logout|status|widgetTypes|index.appname.html|login.appname.html|favicon.ico|(.*)\/vendor\/flags\/.*\.(?:jpg|png)|(.*)\/assets\/images\/company_logo.png)$" 2016/11/15 19:11:38 [debug] 30743#30743: *162 using configuration "/" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http cl:26358 max:1073741824 2016/11/15 19:11:38 [debug] 30743#30743: *162 rewrite phase: 3 2016/11/15 19:11:38 [debug] 30743#30743: *162 post rewrite phase: 4 2016/11/15 19:11:38 [debug] 30743#30743: *162 generic phase: 5 2016/11/15 19:11:38 [debug] 30743#30743: *162 generic phase: 6 2016/11/15 19:11:38 [debug] 30743#30743: *162 generic phase: 7 2016/11/15 19:11:38 [debug] 30743#30743: *162 access phase: 8 2016/11/15 19:11:38 [debug] 30743#30743: *162 access phase: 9 2016/11/15 19:11:38 [debug] 30743#30743: *162 access phase: 10 2016/11/15 19:11:38 [debug] 30743#30743: *162 auth request handler 2016/11/15 19:11:38 [debug] 30743#30743: *162 posix_memalign: 00000F0D34EB6570:4096 @16 2016/11/15 19:11:38 [debug] 30743#30743: *162 http subrequest "/authorize?" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http posted request: "/authorize?" 2016/11/15 19:11:38 [debug] 30743#30743: *162 rewrite phase: 1 2016/11/15 19:11:38 [debug] 30743#30743: *162 test location: "^/widgets/$" 2016/11/15 19:11:38 [debug] 30743#30743: *162 test location: "/" 2016/11/15 19:11:38 [debug] 30743#30743: *162 test location: "docs/" 2016/11/15 19:11:38 [debug] 30743#30743: *162 test location: "dashboard" 2016/11/15 19:11:38 [debug] 30743#30743: *162 test location: "authorize" 2016/11/15 19:11:38 [debug] 30743#30743: *162 using configuration "=/authorize" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http cl:26358 max:1073741824 2016/11/15 19:11:38 [debug] 30743#30743: *162 rewrite phase: 3 2016/11/15 19:11:38 [debug] 30743#30743: *162 post rewrite phase: 4 2016/11/15 19:11:38 [debug] 30743#30743: *162 generic phase: 5 2016/11/15 19:11:38 [debug] 30743#30743: *162 generic phase: 6 2016/11/15 19:11:38 [debug] 30743#30743: *162 generic phase: 7 2016/11/15 19:11:38 [debug] 30743#30743: *162 http init upstream, client timer: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 posix_memalign: 00000F0D34EB7580:4096 @16 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "X-Real-IP: " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script var: "192.168.123.11" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "X-Forwarded-For: " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script var: "192.168.123.11" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "Host: " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script var: "app3.mydomain.local" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "X-NginX-Proxy: true " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "X-Client-S-DN: " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script var: "XXX" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "X-Client-Serial: " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script var: "XXXX" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "x-appname-uri: " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script var: "/appname/v2/heartbeat" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "x-appname-method: " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script var: "POST" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "Connection: close " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "accept: application/json, text/plain, */*" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "origin: https://app3.mydomain.local" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "appname-csrf-token: YYY 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.75 Safari/537.36" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "content-type: application/json;charset=UTF-8" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "accept-encoding: gzip, deflate, br" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "accept-language: en-US,en;q=0.8" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "cookie: XXX" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "GET /authorize HTTP/1.1 X-Real-IP: 192.168.123.11 X-Forwarded-For: 192.168.123.11 Host: app3.mydomain.local X-NginX-Proxy: true x-appname-uri: /appname/v2/heartbeat x-appname-method: POST Connection: close accept: application/json, text/plain, */* origin: https://app3.mydomain.local appname-csrf-token: YYY user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.75 Safari/537.36 content-type: application/json;charset=UTF-8 accept-encoding: gzip, deflate, br accept-language: en-US,en;q=0.8 2016/11/15 19:11:38 [debug] 30743#30743: *162 http cleanup add: 00000F0D34E64460 2016/11/15 19:11:38 [debug] 30743#30743: *162 get rr peer, try: 1 2016/11/15 19:11:38 [debug] 30743#30743: *162 stream socket 7 2016/11/15 19:11:38 [debug] 30743#30743: *162 epoll add connection: fd:7 ev:80002005 2016/11/15 19:11:38 [debug] 30743#30743: *162 connect to 127.0.0.1:8008, fd:7 #569 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream connect: -2 2016/11/15 19:11:38 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBBA30:128 @16 2016/11/15 19:11:38 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237158428 2016/11/15 19:11:38 [debug] 30743#30743: *162 http finalize request: -4, "/authorize?" a:1, c:3 2016/11/15 19:11:38 [debug] 30743#30743: *162 http request count:3 blk:0 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AC047 end:00006EFC4F5AED0C 2016/11/15 19:11:38 [debug] 30743#30743: *162 process http2 frame type:6 f:0 l:8 sid:0 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 PING frame, flags: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AC058 end:00006EFC4F5AED0C 2016/11/15 19:11:38 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:427 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:38 [debug] 30743#30743: *162 malloc: 00000F0D34D89720:65536 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5ACB85 end:00006EFC4F5AED0C 2016/11/15 19:11:38 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:427 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AD6B2 end:00006EFC4F5AED0C 2016/11/15 19:11:38 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:427 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AE1DF end:00006EFC4F5AED0C 2016/11/15 19:11:38 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:427 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AED0C end:00006EFC4F5AED0C 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 frame out: 00000F0D34E03E20 sid:0 bl:0 len:8 2016/11/15 19:11:38 [debug] 30743#30743: *162 malloc: 00000F0D34D83A10:16384 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL buf copy: 17 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL to write: 17 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL_write: 17 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 frame sent: 00000F0D34E03E20 sid:0 bl:0 len:8 2016/11/15 19:11:38 [debug] 30743#30743: *162 event timer del: 3: 1479237268418 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 write handler 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 read handler 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL_read: 699 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL_read: -1 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL_get_error: 2 2016/11/15 19:11:38 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:427 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5ACB3D end:00006EFC4F5AFAAC 2016/11/15 19:11:38 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:427 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AD66A end:00006EFC4F5AFAAC 2016/11/15 19:11:38 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:427 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AE197 end:00006EFC4F5AFAAC 2016/11/15 19:11:38 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:427 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AECC4 end:00006EFC4F5AFAAC 2016/11/15 19:11:38 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:427 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AF7F1 end:00006EFC4F5AFAAC 2016/11/15 19:11:38 [debug] 30743#30743: *162 process http2 frame type:0 f:1 l:690 sid:427 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AFAAC end:00006EFC4F5AFAAC 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 write handler 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream request: "/authorize?" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream send request handler 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream send request 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream send request body 2016/11/15 19:11:38 [debug] 30743#30743: *162 chain writer buf fl:1 s:2711 2016/11/15 19:11:38 [debug] 30743#30743: *162 chain writer in: 00000F0D34EB7550 2016/11/15 19:11:38 [debug] 30743#30743: *162 writev: 2711 of 2711 2016/11/15 19:11:38 [debug] 30743#30743: *162 chain writer out: 0000000000000000 2016/11/15 19:11:38 [debug] 30743#30743: *162 event timer del: 7: 1479237158428 2016/11/15 19:11:38 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237158429 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream request: "/authorize?" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream process header 2016/11/15 19:11:38 [debug] 30743#30743: *162 malloc: 00000F0D34DBC950:4096 2016/11/15 19:11:38 [debug] 30743#30743: *162 recv: fd:7 172 of 4096 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy status 200 "200 OK" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "X-Powered-By: Express" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "x-appname-origin: appname3" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "content-type: application/json" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "content-length: 0" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "Date: Tue, 15 Nov 2016 19:11:38 GMT" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "Connection: close" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header done 2016/11/15 19:11:38 [debug] 30743#30743: *162 lua capture header filter, uri "/authorize" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 header filter 2016/11/15 19:11:38 [debug] 30743#30743: *162 finalize http upstream request: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 finalize http proxy request 2016/11/15 19:11:38 [debug] 30743#30743: *162 free rr peer 1 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 close http upstream connection: 7 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34DBBA30, unused: 48 2016/11/15 19:11:38 [debug] 30743#30743: *162 event timer del: 7: 1479237158429 2016/11/15 19:11:38 [debug] 30743#30743: *162 reusable connection: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 http finalize request: 0, "/authorize?" a:1, c:2 2016/11/15 19:11:38 [debug] 30743#30743: *162 auth request done s:200 2016/11/15 19:11:38 [debug] 30743#30743: *162 http wake parent request: "/appname/v2/heartbeat?" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http posted request: "/appname/v2/heartbeat?" 2016/11/15 19:11:38 [debug] 30743#30743: *162 access phase: 10 2016/11/15 19:11:38 [debug] 30743#30743: *162 auth request handler 2016/11/15 19:11:38 [debug] 30743#30743: *162 auth request set variables 2016/11/15 19:11:38 [debug] 30743#30743: *162 access phase: 11 2016/11/15 19:11:38 [debug] 30743#30743: *162 lua access handler, uri:"/appname/v2/heartbeat" c:1 2016/11/15 19:11:38 [debug] 30743#30743: *162 post access phase: 12 2016/11/15 19:11:38 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBD960:4096 @16 2016/11/15 19:11:38 [debug] 30743#30743: *162 http body new buf t:1 f:0 00000F0D34D89720, pos 00000F0D34D89720, size: 26358 file: 0, size: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 http init upstream, client timer: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "X-Real-IP: " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script var: "192.168.123.11" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "X-Forwarded-For: " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script var: "192.168.123.11" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "Host: " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script var: "app3.mydomain.local" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "X-NginX-Proxy: true " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "X-Client-S-DN: " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script var: "XXX" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "X-Client-Serial: " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script var: "XXXX" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "Connection: close " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "Content-Length: " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script var: "26358" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "accept: application/json, text/plain, */*" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "origin: https://app3.mydomain.local" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "appname-csrf-token: YYY 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.75 Safari/537.36" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "content-type: application/json;charset=UTF-8" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "accept-encoding: gzip, deflate, br" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "accept-language: en-US,en;q=0.8" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "cookie: XXX" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "POST /appname/v2/heartbeat HTTP/1.1 X-Real-IP: 192.168.123.11 X-Forwarded-For: 192.168.123.11 Host: app3.mydomain.local X-NginX-Proxy: true Connection: close Content-Length: 26358 accept: application/json, text/plain, */* origin: https://app3.mydomain.local appname-csrf-token: YYY user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.75 Safari/537.36 content-type: application/json;charset=UTF-8 accept-encoding: gzip, deflate, br accept-language: en-US,en;q=0.8 2016/11/15 19:11:38 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBE970:4096 @16 2016/11/15 19:11:38 [debug] 30743#30743: *162 http cleanup add: 00000F0D34DBE938 2016/11/15 19:11:38 [debug] 30743#30743: *162 get rr peer, try: 1 2016/11/15 19:11:38 [debug] 30743#30743: *162 stream socket 7 2016/11/15 19:11:38 [debug] 30743#30743: *162 epoll add connection: fd:7 ev:80002005 2016/11/15 19:11:38 [debug] 30743#30743: *162 connect to 182.168.128.69:8080, fd:7 #570 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream connect: -2 2016/11/15 19:11:38 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBBA30:128 @16 2016/11/15 19:11:38 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237158454 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34D89720 2016/11/15 19:11:38 [debug] 30743#30743: *162 http finalize request: -4, "/appname/v2/heartbeat?" a:1, c:2 2016/11/15 19:11:38 [debug] 30743#30743: *162 http request count:2 blk:0 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream send request handler 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream send request 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream send request body 2016/11/15 19:11:38 [debug] 30743#30743: *162 chain writer buf fl:0 s:2690 2016/11/15 19:11:38 [debug] 30743#30743: *162 chain writer buf fl:1 s:26358 2016/11/15 19:11:38 [debug] 30743#30743: *162 chain writer in: 00000F0D34DBEA00 2016/11/15 19:11:38 [debug] 30743#30743: *162 writev: 28960 of 29048 2016/11/15 19:11:38 [debug] 30743#30743: *162 chain writer out: 00000F0D34DBEA10 2016/11/15 19:11:38 [debug] 30743#30743: *162 event timer: 7, old: 1479237158454, new: 1479237158455 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream send request handler 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream send request 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream send request body 2016/11/15 19:11:38 [debug] 30743#30743: *162 chain writer in: 00000F0D34DBEA10 2016/11/15 19:11:38 [debug] 30743#30743: *162 writev: 88 of 88 2016/11/15 19:11:38 [debug] 30743#30743: *162 chain writer out: 0000000000000000 2016/11/15 19:11:38 [debug] 30743#30743: *162 event timer del: 7: 1479237158454 2016/11/15 19:11:38 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237158456 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream process header 2016/11/15 19:11:38 [debug] 30743#30743: *162 malloc: 00000F0D34D69D00:4096 2016/11/15 19:11:38 [debug] 30743#30743: *162 recv: fd:7 1056 of 4096 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy status 400 "400 Bad Request" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "Server: nginx" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "Date: Tue, 15 Nov 2016 19:11:39 GMT" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "Content-Type: text/html; charset=utf-8" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "Content-Length: 840" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "Connection: close" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "X-Powered-By: Express" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "X-Content-Type-Options: nosniff" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header done 2016/11/15 19:11:38 [debug] 30743#30743: *162 lua capture header filter, uri "/appname/v2/heartbeat" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 header filter 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 output header: ":status: 400" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 output header: "server: nginx" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 output header: "date: Tue, 15 Nov 2016 19:11:38 GMT" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 output header: "content-type: text/html; charset=utf-8" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 output header: "content-length: 840" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 output header: "x-powered-by: Express" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 output header: "x-content-type-options: nosniff" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2:427 create HEADERS frame 00000F0D34DBEDA8: len:98 2016/11/15 19:11:38 [debug] 30743#30743: *162 http cleanup add: 00000F0D34DBEE90 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 frame out: 00000F0D34DBEDA8 sid:427 bl:1 len:98 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL buf copy: 9 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL buf copy: 98 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2:427 HEADERS frame 00000F0D34DBEDA8 was sent 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 frame sent: 00000F0D34DBEDA8 sid:427 bl:1 len:98 2016/11/15 19:11:38 [debug] 30743#30743: *162 http cacheable: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy filter init s:400 h:0 c:0 l:840 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream process upstream 2016/11/15 19:11:38 [debug] 30743#30743: *162 pipe read upstream: 1 2016/11/15 19:11:38 [debug] 30743#30743: *162 pipe preread: 840 2016/11/15 19:11:38 [debug] 30743#30743: *162 readv: 1, last:3040 2016/11/15 19:11:38 [debug] 30743#30743: *162 pipe recv chain: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 pipe buf free s:0 t:1 f:0 00000F0D34D69D00, pos 00000F0D34D69DD8, size: 840 file: 0, size: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 pipe length: 840 2016/11/15 19:11:38 [debug] 30743#30743: *162 input buf #0 2016/11/15 19:11:38 [debug] 30743#30743: *162 pipe write downstream: 1 2016/11/15 19:11:38 [debug] 30743#30743: *162 pipe write downstream flush in 2016/11/15 19:11:38 [debug] 30743#30743: *162 http output filter "/appname/v2/heartbeat?" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http copy filter: "/appname/v2/heartbeat?" 2016/11/15 19:11:38 [debug] 30743#30743: *162 lua capture body filter, uri "/appname/v2/heartbeat" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http postpone filter "/appname/v2/heartbeat?" 00000F0D34DBEA00 2016/11/15 19:11:38 [debug] 30743#30743: *162 write new buf t:1 f:0 00000F0D34D69D00, pos 00000F0D34D69DD8, size: 840 file: 0, size: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 http write filter: l:0 f:0 s:840 2016/11/15 19:11:38 [debug] 30743#30743: *162 http copy filter: 0 "/appname/v2/heartbeat?" 2016/11/15 19:11:38 [debug] 30743#30743: *162 pipe write downstream done 2016/11/15 19:11:38 [debug] 30743#30743: *162 event timer: 7, old: 1479237158456, new: 1479237158485 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream exit: 0000000000000000 2016/11/15 19:11:38 [debug] 30743#30743: *162 finalize http upstream request: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 finalize http proxy request 2016/11/15 19:11:38 [debug] 30743#30743: *162 free rr peer 1 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 close http upstream connection: 7 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34DBBA30, unused: 48 2016/11/15 19:11:38 [debug] 30743#30743: *162 event timer del: 7: 1479237158456 2016/11/15 19:11:38 [debug] 30743#30743: *162 reusable connection: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream temp fd: -1 2016/11/15 19:11:38 [debug] 30743#30743: *162 http output filter "/appname/v2/heartbeat?" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http copy filter: "/appname/v2/heartbeat?" 2016/11/15 19:11:38 [debug] 30743#30743: *162 lua capture body filter, uri "/appname/v2/heartbeat" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http postpone filter "/appname/v2/heartbeat?" 00007A9E70E05A50 2016/11/15 19:11:38 [debug] 30743#30743: *162 write old buf t:1 f:0 00000F0D34D69D00, pos 00000F0D34D69DD8, size: 840 file: 0, size: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 write new buf t:0 f:0 0000000000000000, pos 0000000000000000, size: 0 file: 0, size: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 http write filter: l:1 f:0 s:840 2016/11/15 19:11:38 [debug] 30743#30743: *162 http write filter limit 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2:427 create DATA frame 00000F0D34DBEDA8: len:840 flags:1 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 frame out: 00000F0D34DBEDA8 sid:427 bl:0 len:840 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL buf copy: 9 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL buf copy: 840 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL to write: 956 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL_write: 956 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2:427 DATA frame 00000F0D34DBEDA8 was sent 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 frame sent: 00000F0D34DBEDA8 sid:427 bl:0 len:840 2016/11/15 19:11:38 [debug] 30743#30743: *162 http write filter 0000000000000000 2016/11/15 19:11:38 [debug] 30743#30743: *162 http copy filter: 0 "/appname/v2/heartbeat?" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http finalize request: 0, "/appname/v2/heartbeat?" a:1, c:1 2016/11/15 19:11:38 [debug] 30743#30743: *162 http request count:1 blk:0 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 close stream 427, queued 0, processing 1 2016/11/15 19:11:38 [debug] 30743#30743: *162 http close request 2016/11/15 19:11:38 [debug] 30743#30743: *162 http log handler 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34DBC950 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34D69D00 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34E120F0, unused: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34E63480, unused: 2 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34EB6570, unused: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34EB7580, unused: 8 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34DBD960, unused: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34DBE970, unused: 1926 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34E61530, unused: 162 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34E16F00, unused: 156 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34DC4930, unused: 111 2016/11/15 19:11:38 [debug] 30743#30743: *162 post event 00006EFC4C5081F0 2016/11/15 19:11:38 [debug] 30743#30743: *162 delete posted event 00006EFC4C5081F0 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 handle connection handler 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34E03BC0, unused: 3312 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34D83A10 2016/11/15 19:11:38 [debug] 30743#30743: *162 reusable connection: 1 2016/11/15 19:11:38 [debug] 30743#30743: *162 event timer add: 3: 180000:1479237278485 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 idle handler 2016/11/15 19:11:38 [debug] 30743#30743: *162 reusable connection: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E120F0:4096 @16 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 read handler 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL_read: 55 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL_read: -1 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL_get_error: 2 2016/11/15 19:11:38 [debug] 30743#30743: *162 process http2 frame type:1 f:24 l:46 sid:429 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 HEADERS frame sid:429 on 0 excl:0 weight:183 2016/11/15 19:11:38 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DC4930:1024 @16 2016/11/15 19:11:38 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E03BC0:4096 @16 2016/11/15 19:11:38 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E63480:4096 @16 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header name: 3 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header name: 65 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header name: 7 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 hpack encoded string length: 4 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 hpack encoded string length: 13 2016/11/15 19:11:38 [debug] 30743#30743: *162 http uri: "/appname/v2/heartbeat" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http args: "" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http exten: "" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header: 28 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 hpack encoded string length: 4 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 add header to hpack table: "content-length: 16385" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 hpack table account: 51 free:81 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 http header: "content-length: 16385" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header name: 64 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 http header: "accept: application/json, text/plain, */*" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header name: 76 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 http header: "origin: https://app3.mydomain.local" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header name: 92 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 http header: "appname-csrf-token: YYY 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header name: 95 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 http header: "user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.75 Safari/537.36" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header name: 75 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 http header: "content-type: application/json;charset=UTF-8" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header name: 73 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 http header: "accept-encoding: gzip, deflate, br" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header name: 89 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 http header: "accept-language: en-US,en;q=0.8" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header name: 88 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header name: 87 2016/11/15 19:11:38 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E16F00:1024 @16 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header name: 86 2016/11/15 19:11:38 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E61530:1024 @16 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header name: 85 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 get indexed header name: 91 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 http request line: "POST /appname/v2/heartbeat HTTP/2.0" 2016/11/15 19:11:38 [debug] 30743#30743: *162 generic phase: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 rewrite phase: 1 2016/11/15 19:11:38 [debug] 30743#30743: *162 test location: "^/widgets/$" 2016/11/15 19:11:38 [debug] 30743#30743: *162 test location: "/" 2016/11/15 19:11:38 [debug] 30743#30743: *162 test location: "docs/" 2016/11/15 19:11:38 [debug] 30743#30743: *162 test location: "appname/socket" 2016/11/15 19:11:38 [debug] 30743#30743: *162 test location: ~ "^/(index.html)?$" 2016/11/15 19:11:38 [debug] 30743#30743: *162 test location: ~ "^/login/?$" 2016/11/15 19:11:38 [debug] 30743#30743: *162 test location: ~ "^/(appname)" 2016/11/15 19:11:38 [debug] 30743#30743: *162 test location: ~ "/components/(.*)" 2016/11/15 19:11:38 [debug] 30743#30743: *162 test location: ~ "^/(auth|logout|status|widgetTypes|index.appname.html|login.appname.html|favicon.ico|(.*)\/vendor\/flags\/.*\.(?:jpg|png)|(.*)\/assets\/images\/company_logo.png)$" 2016/11/15 19:11:38 [debug] 30743#30743: *162 using configuration "/" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http cl:16385 max:1073741824 2016/11/15 19:11:38 [debug] 30743#30743: *162 rewrite phase: 3 2016/11/15 19:11:38 [debug] 30743#30743: *162 post rewrite phase: 4 2016/11/15 19:11:38 [debug] 30743#30743: *162 generic phase: 5 2016/11/15 19:11:38 [debug] 30743#30743: *162 generic phase: 6 2016/11/15 19:11:38 [debug] 30743#30743: *162 generic phase: 7 2016/11/15 19:11:38 [debug] 30743#30743: *162 access phase: 8 2016/11/15 19:11:38 [debug] 30743#30743: *162 access phase: 9 2016/11/15 19:11:38 [debug] 30743#30743: *162 access phase: 10 2016/11/15 19:11:38 [debug] 30743#30743: *162 auth request handler 2016/11/15 19:11:38 [debug] 30743#30743: *162 posix_memalign: 00000F0D34EB6570:4096 @16 2016/11/15 19:11:38 [debug] 30743#30743: *162 http subrequest "/authorize?" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http posted request: "/authorize?" 2016/11/15 19:11:38 [debug] 30743#30743: *162 rewrite phase: 1 2016/11/15 19:11:38 [debug] 30743#30743: *162 test location: "^/widgets/$" 2016/11/15 19:11:38 [debug] 30743#30743: *162 test location: "/" 2016/11/15 19:11:38 [debug] 30743#30743: *162 test location: "docs/" 2016/11/15 19:11:38 [debug] 30743#30743: *162 test location: "dashboard" 2016/11/15 19:11:38 [debug] 30743#30743: *162 test location: "authorize" 2016/11/15 19:11:38 [debug] 30743#30743: *162 using configuration "=/authorize" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http cl:16385 max:1073741824 2016/11/15 19:11:38 [debug] 30743#30743: *162 rewrite phase: 3 2016/11/15 19:11:38 [debug] 30743#30743: *162 post rewrite phase: 4 2016/11/15 19:11:38 [debug] 30743#30743: *162 generic phase: 5 2016/11/15 19:11:38 [debug] 30743#30743: *162 generic phase: 6 2016/11/15 19:11:38 [debug] 30743#30743: *162 generic phase: 7 2016/11/15 19:11:38 [debug] 30743#30743: *162 http init upstream, client timer: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 posix_memalign: 00000F0D34EB7580:4096 @16 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "X-Real-IP: " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script var: "192.168.123.11" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "X-Forwarded-For: " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script var: "192.168.123.11" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "Host: " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script var: "app3.mydomain.local" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "X-NginX-Proxy: true " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "X-Client-S-DN: " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script var: "XXX" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "X-Client-Serial: " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script var: "XXXX" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "x-appname-uri: " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script var: "/appname/v2/heartbeat" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "x-appname-method: " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script var: "POST" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "Connection: close " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "accept: application/json, text/plain, */*" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "origin: https://app3.mydomain.local" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "appname-csrf-token: YYY 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.75 Safari/537.36" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "content-type: application/json;charset=UTF-8" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "accept-encoding: gzip, deflate, br" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "accept-language: en-US,en;q=0.8" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "cookie: XXX" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "GET /authorize HTTP/1.1 X-Real-IP: 192.168.123.11 X-Forwarded-For: 192.168.123.11 Host: app3.mydomain.local X-NginX-Proxy: true x-appname-uri: /appname/v2/heartbeat x-appname-method: POST Connection: close accept: application/json, text/plain, */* origin: https://app3.mydomain.local appname-csrf-token: YYY user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.75 Safari/537.36 content-type: application/json;charset=UTF-8 accept-encoding: gzip, deflate, br accept-language: en-US,en;q=0.8 2016/11/15 19:11:38 [debug] 30743#30743: *162 http cleanup add: 00000F0D34E64460 2016/11/15 19:11:38 [debug] 30743#30743: *162 get rr peer, try: 1 2016/11/15 19:11:38 [debug] 30743#30743: *162 stream socket 7 2016/11/15 19:11:38 [debug] 30743#30743: *162 epoll add connection: fd:7 ev:80002005 2016/11/15 19:11:38 [debug] 30743#30743: *162 connect to 127.0.0.1:8008, fd:7 #571 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream connect: -2 2016/11/15 19:11:38 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBBA30:128 @16 2016/11/15 19:11:38 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237158567 2016/11/15 19:11:38 [debug] 30743#30743: *162 http finalize request: -4, "/authorize?" a:1, c:3 2016/11/15 19:11:38 [debug] 30743#30743: *162 http request count:3 blk:0 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AC047 end:00006EFC4F5AC047 2016/11/15 19:11:38 [debug] 30743#30743: *162 event timer del: 3: 1479237278485 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 write handler 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 read handler 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL_read: 2134 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL_read: -1 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL_get_error: 2 2016/11/15 19:11:38 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:429 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:38 [debug] 30743#30743: *162 malloc: 00000F0D34D89720:65536 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5ACB3D end:00006EFC4F5B0047 2016/11/15 19:11:38 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:429 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AD66A end:00006EFC4F5B0047 2016/11/15 19:11:38 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:429 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AE197 end:00006EFC4F5B0047 2016/11/15 19:11:38 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:429 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AECC4 end:00006EFC4F5B0047 2016/11/15 19:11:38 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:429 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AF7F1 end:00006EFC4F5B0047 2016/11/15 19:11:38 [debug] 30743#30743: *162 process http2 frame type:0 f:1 l:2125 sid:429 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 DATA frame 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5B0047 end:00006EFC4F5B0047 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 write handler 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream request: "/authorize?" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream send request handler 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream send request 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream send request body 2016/11/15 19:11:38 [debug] 30743#30743: *162 chain writer buf fl:1 s:2711 2016/11/15 19:11:38 [debug] 30743#30743: *162 chain writer in: 00000F0D34EB7550 2016/11/15 19:11:38 [debug] 30743#30743: *162 writev: 2711 of 2711 2016/11/15 19:11:38 [debug] 30743#30743: *162 chain writer out: 0000000000000000 2016/11/15 19:11:38 [debug] 30743#30743: *162 event timer del: 7: 1479237158567 2016/11/15 19:11:38 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237158567 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream request: "/authorize?" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream process header 2016/11/15 19:11:38 [debug] 30743#30743: *162 malloc: 00000F0D34DBC950:4096 2016/11/15 19:11:38 [debug] 30743#30743: *162 recv: fd:7 172 of 4096 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy status 200 "200 OK" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "X-Powered-By: Express" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "x-appname-origin: appname3" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "content-type: application/json" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "content-length: 0" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "Date: Tue, 15 Nov 2016 19:11:38 GMT" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "Connection: close" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header done 2016/11/15 19:11:38 [debug] 30743#30743: *162 lua capture header filter, uri "/authorize" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 header filter 2016/11/15 19:11:38 [debug] 30743#30743: *162 finalize http upstream request: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 finalize http proxy request 2016/11/15 19:11:38 [debug] 30743#30743: *162 free rr peer 1 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 close http upstream connection: 7 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34DBBA30, unused: 48 2016/11/15 19:11:38 [debug] 30743#30743: *162 event timer del: 7: 1479237158567 2016/11/15 19:11:38 [debug] 30743#30743: *162 reusable connection: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 http finalize request: 0, "/authorize?" a:1, c:2 2016/11/15 19:11:38 [debug] 30743#30743: *162 auth request done s:200 2016/11/15 19:11:38 [debug] 30743#30743: *162 http wake parent request: "/appname/v2/heartbeat?" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http posted request: "/appname/v2/heartbeat?" 2016/11/15 19:11:38 [debug] 30743#30743: *162 access phase: 10 2016/11/15 19:11:38 [debug] 30743#30743: *162 auth request handler 2016/11/15 19:11:38 [debug] 30743#30743: *162 auth request set variables 2016/11/15 19:11:38 [debug] 30743#30743: *162 access phase: 11 2016/11/15 19:11:38 [debug] 30743#30743: *162 lua access handler, uri:"/appname/v2/heartbeat" c:1 2016/11/15 19:11:38 [debug] 30743#30743: *162 post access phase: 12 2016/11/15 19:11:38 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBD960:4096 @16 2016/11/15 19:11:38 [debug] 30743#30743: *162 http body new buf t:1 f:0 00000F0D34D89720, pos 00000F0D34D89720, size: 16385 file: 0, size: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 http init upstream, client timer: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "X-Real-IP: " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script var: "192.168.123.11" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "X-Forwarded-For: " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script var: "192.168.123.11" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "Host: " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script var: "app3.mydomain.local" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "X-NginX-Proxy: true " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "X-Client-S-DN: " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script var: "XXX" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "X-Client-Serial: " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script var: "XXXX" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "Connection: close " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "Content-Length: " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script var: "16385" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http script copy: "" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "accept: application/json, text/plain, */*" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "origin: https://app3.mydomain.local" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "appname-csrf-token: YYY 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.75 Safari/537.36" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "content-type: application/json;charset=UTF-8" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "accept-encoding: gzip, deflate, br" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "accept-language: en-US,en;q=0.8" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "cookie: XXX" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "POST /appname/v2/heartbeat HTTP/1.1 X-Real-IP: 192.168.123.11 X-Forwarded-For: 192.168.123.11 Host: app3.mydomain.local X-NginX-Proxy: true Connection: close Content-Length: 16385 accept: application/json, text/plain, */* origin: https://app3.mydomain.local appname-csrf-token: YYY user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.75 Safari/537.36 content-type: application/json;charset=UTF-8 accept-encoding: gzip, deflate, br accept-language: en-US,en;q=0.8 2016/11/15 19:11:38 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBE970:4096 @16 2016/11/15 19:11:38 [debug] 30743#30743: *162 http cleanup add: 00000F0D34DBE938 2016/11/15 19:11:38 [debug] 30743#30743: *162 get rr peer, try: 1 2016/11/15 19:11:38 [debug] 30743#30743: *162 stream socket 7 2016/11/15 19:11:38 [debug] 30743#30743: *162 epoll add connection: fd:7 ev:80002005 2016/11/15 19:11:38 [debug] 30743#30743: *162 connect to 182.168.128.69:8080, fd:7 #572 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream connect: -2 2016/11/15 19:11:38 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBBA30:128 @16 2016/11/15 19:11:38 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237158590 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34D89720 2016/11/15 19:11:38 [debug] 30743#30743: *162 http finalize request: -4, "/appname/v2/heartbeat?" a:1, c:2 2016/11/15 19:11:38 [debug] 30743#30743: *162 http request count:2 blk:0 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream send request handler 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream send request 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream send request body 2016/11/15 19:11:38 [debug] 30743#30743: *162 chain writer buf fl:0 s:2690 2016/11/15 19:11:38 [debug] 30743#30743: *162 chain writer buf fl:1 s:16385 2016/11/15 19:11:38 [debug] 30743#30743: *162 chain writer in: 00000F0D34DBEA00 2016/11/15 19:11:38 [debug] 30743#30743: *162 writev: 19075 of 19075 2016/11/15 19:11:38 [debug] 30743#30743: *162 chain writer out: 0000000000000000 2016/11/15 19:11:38 [debug] 30743#30743: *162 event timer del: 7: 1479237158590 2016/11/15 19:11:38 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237158591 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream process header 2016/11/15 19:11:38 [debug] 30743#30743: *162 malloc: 00000F0D34D69D00:4096 2016/11/15 19:11:38 [debug] 30743#30743: *162 recv: fd:7 1056 of 4096 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy status 400 "400 Bad Request" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "Server: nginx" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "Date: Tue, 15 Nov 2016 19:11:38 GMT" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "Content-Type: text/html; charset=utf-8" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "Content-Length: 840" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "Connection: close" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "X-Powered-By: Express" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header: "X-Content-Type-Options: nosniff" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy header done 2016/11/15 19:11:38 [debug] 30743#30743: *162 lua capture header filter, uri "/appname/v2/heartbeat" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 header filter 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 output header: ":status: 400" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 output header: "server: nginx" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 output header: "date: Tue, 15 Nov 2016 19:11:38 GMT" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 output header: "content-type: text/html; charset=utf-8" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 output header: "content-length: 840" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 output header: "x-powered-by: Express" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 output header: "x-content-type-options: nosniff" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2:429 create HEADERS frame 00000F0D34DBEDA8: len:98 2016/11/15 19:11:38 [debug] 30743#30743: *162 http cleanup add: 00000F0D34DBEE90 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 frame out: 00000F0D34DBEDA8 sid:429 bl:1 len:98 2016/11/15 19:11:38 [debug] 30743#30743: *162 malloc: 00000F0D34D83A10:16384 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL buf copy: 9 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL buf copy: 98 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2:429 HEADERS frame 00000F0D34DBEDA8 was sent 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 frame sent: 00000F0D34DBEDA8 sid:429 bl:1 len:98 2016/11/15 19:11:38 [debug] 30743#30743: *162 http cacheable: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 http proxy filter init s:400 h:0 c:0 l:840 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream process upstream 2016/11/15 19:11:38 [debug] 30743#30743: *162 pipe read upstream: 1 2016/11/15 19:11:38 [debug] 30743#30743: *162 pipe preread: 840 2016/11/15 19:11:38 [debug] 30743#30743: *162 readv: 1, last:3040 2016/11/15 19:11:38 [debug] 30743#30743: *162 pipe recv chain: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 pipe buf free s:0 t:1 f:0 00000F0D34D69D00, pos 00000F0D34D69DD8, size: 840 file: 0, size: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 pipe length: 840 2016/11/15 19:11:38 [debug] 30743#30743: *162 input buf #0 2016/11/15 19:11:38 [debug] 30743#30743: *162 pipe write downstream: 1 2016/11/15 19:11:38 [debug] 30743#30743: *162 pipe write downstream flush in 2016/11/15 19:11:38 [debug] 30743#30743: *162 http output filter "/appname/v2/heartbeat?" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http copy filter: "/appname/v2/heartbeat?" 2016/11/15 19:11:38 [debug] 30743#30743: *162 lua capture body filter, uri "/appname/v2/heartbeat" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http postpone filter "/appname/v2/heartbeat?" 00000F0D34DBEA00 2016/11/15 19:11:38 [debug] 30743#30743: *162 write new buf t:1 f:0 00000F0D34D69D00, pos 00000F0D34D69DD8, size: 840 file: 0, size: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 http write filter: l:0 f:0 s:840 2016/11/15 19:11:38 [debug] 30743#30743: *162 http copy filter: 0 "/appname/v2/heartbeat?" 2016/11/15 19:11:38 [debug] 30743#30743: *162 pipe write downstream done 2016/11/15 19:11:38 [debug] 30743#30743: *162 event timer: 7, old: 1479237158591, new: 1479237158599 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream exit: 0000000000000000 2016/11/15 19:11:38 [debug] 30743#30743: *162 finalize http upstream request: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 finalize http proxy request 2016/11/15 19:11:38 [debug] 30743#30743: *162 free rr peer 1 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 close http upstream connection: 7 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34DBBA30, unused: 48 2016/11/15 19:11:38 [debug] 30743#30743: *162 event timer del: 7: 1479237158591 2016/11/15 19:11:38 [debug] 30743#30743: *162 reusable connection: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 http upstream temp fd: -1 2016/11/15 19:11:38 [debug] 30743#30743: *162 http output filter "/appname/v2/heartbeat?" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http copy filter: "/appname/v2/heartbeat?" 2016/11/15 19:11:38 [debug] 30743#30743: *162 lua capture body filter, uri "/appname/v2/heartbeat" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http postpone filter "/appname/v2/heartbeat?" 00007A9E70E05A50 2016/11/15 19:11:38 [debug] 30743#30743: *162 write old buf t:1 f:0 00000F0D34D69D00, pos 00000F0D34D69DD8, size: 840 file: 0, size: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 write new buf t:0 f:0 0000000000000000, pos 0000000000000000, size: 0 file: 0, size: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 http write filter: l:1 f:0 s:840 2016/11/15 19:11:38 [debug] 30743#30743: *162 http write filter limit 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2:429 create DATA frame 00000F0D34DBEDA8: len:840 flags:1 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 frame out: 00000F0D34DBEDA8 sid:429 bl:0 len:840 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL buf copy: 9 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL buf copy: 840 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL to write: 956 2016/11/15 19:11:38 [debug] 30743#30743: *162 SSL_write: 956 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2:429 DATA frame 00000F0D34DBEDA8 was sent 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 frame sent: 00000F0D34DBEDA8 sid:429 bl:0 len:840 2016/11/15 19:11:38 [debug] 30743#30743: *162 http write filter 0000000000000000 2016/11/15 19:11:38 [debug] 30743#30743: *162 http copy filter: 0 "/appname/v2/heartbeat?" 2016/11/15 19:11:38 [debug] 30743#30743: *162 http finalize request: 0, "/appname/v2/heartbeat?" a:1, c:1 2016/11/15 19:11:38 [debug] 30743#30743: *162 http request count:1 blk:0 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 close stream 429, queued 0, processing 1 2016/11/15 19:11:38 [debug] 30743#30743: *162 http close request 2016/11/15 19:11:38 [debug] 30743#30743: *162 http log handler 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34DBC950 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34D69D00 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34E03BC0, unused: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34E63480, unused: 2 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34EB6570, unused: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34EB7580, unused: 8 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34DBD960, unused: 0 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34DBE970, unused: 1926 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34DC4930, unused: 162 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34E16F00, unused: 156 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34E61530, unused: 111 2016/11/15 19:11:38 [debug] 30743#30743: *162 post event 00006EFC4C5081F0 2016/11/15 19:11:38 [debug] 30743#30743: *162 delete posted event 00006EFC4C5081F0 2016/11/15 19:11:38 [debug] 30743#30743: *162 http2 handle connection handler 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34E120F0, unused: 3488 2016/11/15 19:11:38 [debug] 30743#30743: *162 free: 00000F0D34D83A10 2016/11/15 19:11:38 [debug] 30743#30743: *162 reusable connection: 1 2016/11/15 19:11:38 [debug] 30743#30743: *162 event timer add: 3: 180000:1479237278599 2016/11/15 19:11:48 [debug] 30741#30741: *251 post event 00006EFC4C5081F0 2016/11/15 19:11:48 [debug] 30741#30741: *251 post event 00006EFC4C2071F0 2016/11/15 19:11:48 [debug] 30741#30741: *251 delete posted event 00006EFC4C5081F0 2016/11/15 19:11:48 [debug] 30741#30741: *251 http run request: "/appname/socket/?EIO=3&transport=websocket&sid=UJyFqU73bEe42MVkAAAB" 2016/11/15 19:11:48 [debug] 30741#30741: *251 http upstream process upgraded, fu:0 2016/11/15 19:11:48 [debug] 30741#30741: *251 SSL_read: 9 2016/11/15 19:11:48 [debug] 30741#30741: *251 SSL_read: -1 2016/11/15 19:11:48 [debug] 30741#30741: *251 SSL_get_error: 2 2016/11/15 19:11:48 [debug] 30741#30741: *251 send: fd:14 9 of 9 2016/11/15 19:11:48 [debug] 30741#30741: *251 event timer del: 14: 1479237143065 2016/11/15 19:11:48 [debug] 30741#30741: *251 event timer add: 14: 60000:1479237168070 2016/11/15 19:11:48 [debug] 30741#30741: *251 delete posted event 00006EFC4C2071F0 2016/11/15 19:11:48 [debug] 30741#30741: *251 http run request: "/appname/socket/?EIO=3&transport=websocket&sid=UJyFqU73bEe42MVkAAAB" 2016/11/15 19:11:48 [debug] 30741#30741: *251 http upstream process upgraded, fu:1 2016/11/15 19:11:48 [debug] 30741#30741: *251 event timer: 14, old: 1479237168070, new: 1479237168070 2016/11/15 19:11:48 [debug] 30741#30741: *251 post event 00006EFC4C508250 2016/11/15 19:11:48 [debug] 30741#30741: *251 post event 00006EFC4C207250 2016/11/15 19:11:48 [debug] 30741#30741: *251 delete posted event 00006EFC4C508250 2016/11/15 19:11:48 [debug] 30741#30741: *251 http upstream request: "/appname/socket/?EIO=3&transport=websocket&sid=UJyFqU73bEe42MVkAAAB" 2016/11/15 19:11:48 [debug] 30741#30741: *251 http upstream process upgraded, fu:1 2016/11/15 19:11:48 [debug] 30741#30741: *251 recv: fd:14 3 of 4096 2016/11/15 19:11:48 [debug] 30741#30741: *251 SSL to write: 3 2016/11/15 19:11:48 [debug] 30741#30741: *251 SSL_write: 3 2016/11/15 19:11:48 [debug] 30741#30741: *251 recv: fd:14 -1 of 4096 2016/11/15 19:11:48 [debug] 30741#30741: *251 recv() not ready (11: Resource temporarily unavailable) 2016/11/15 19:11:48 [debug] 30741#30741: *251 event timer: 14, old: 1479237168070, new: 1479237168073 2016/11/15 19:11:48 [debug] 30741#30741: *251 delete posted event 00006EFC4C207250 2016/11/15 19:11:48 [debug] 30741#30741: *251 http upstream request: "/appname/socket/?EIO=3&transport=websocket&sid=UJyFqU73bEe42MVkAAAB" 2016/11/15 19:11:48 [debug] 30741#30741: *251 http upstream process upgraded, fu:0 2016/11/15 19:11:48 [debug] 30741#30741: *251 event timer: 14, old: 1479237168070, new: 1479237168073 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 idle handler 2016/11/15 19:11:48 [debug] 30743#30743: *162 reusable connection: 0 2016/11/15 19:11:48 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E03BC0:4096 @16 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 read handler 2016/11/15 19:11:48 [debug] 30743#30743: *162 SSL_read: 136 2016/11/15 19:11:48 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:48 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:48 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:48 [debug] 30743#30743: *162 SSL_read: 2861 2016/11/15 19:11:48 [debug] 30743#30743: *162 SSL_read: -1 2016/11/15 19:11:48 [debug] 30743#30743: *162 SSL_get_error: 2 2016/11/15 19:11:48 [debug] 30743#30743: *162 process http2 frame type:1 f:24 l:127 sid:431 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 HEADERS frame sid:431 on 0 excl:0 weight:183 2016/11/15 19:11:48 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E61530:1024 @16 2016/11/15 19:11:48 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E120F0:4096 @16 2016/11/15 19:11:48 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E63480:4096 @16 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 get indexed header name: 3 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 get indexed header name: 66 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 get indexed header name: 7 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 hpack encoded string length: 4 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 hpack encoded string length: 13 2016/11/15 19:11:48 [debug] 30743#30743: *162 http uri: "/appname/v2/heartbeat" 2016/11/15 19:11:48 [debug] 30743#30743: *162 http args: "" 2016/11/15 19:11:48 [debug] 30743#30743: *162 http exten: "" 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 get indexed header: 28 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 hpack encoded string length: 4 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 add header to hpack table: "content-length: 26568" 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 hpack table account: 51 free:30 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 http header: "content-length: 26568" 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 get indexed header name: 65 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 http header: "accept: application/json, text/plain, */*" 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 get indexed header name: 77 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 http header: "origin: https://app3.mydomain.local" 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 get indexed header name: 93 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 http header: "appname-csrf-token: YYY 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 get indexed header: 58 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 hpack encoded string length: 80 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 add header to hpack table: "user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.75 Safari/537.36" 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 hpack table account: 146 free:125 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 http header: "user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.75 Safari/537.36" 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 get indexed header name: 77 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 http header: "content-type: application/json;charset=UTF-8" 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 get indexed header name: 75 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 http header: "accept-encoding: gzip, deflate, br" 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 get indexed header name: 91 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 http header: "accept-language: en-US,en;q=0.8" 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 get indexed header name: 90 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 get indexed header name: 89 2016/11/15 19:11:48 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E16F00:1024 @16 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 get indexed header name: 88 2016/11/15 19:11:48 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DC4930:1024 @16 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 get indexed header name: 87 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 get indexed header name: 93 2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 http request line: "POST /appname/v2/heartbeat HTTP/2.0" 2016/11/15 19:11:48 [debug] 30743#30743: *162 generic phase: 0 2016/11/15 19:11:48 [debug] 30743#30743: *162 rewrite phase: 1 2016/11/15 19:11:48 [debug] 30743#30743: *162 test location: "^/widgets/$" 2016/11/15 19:11:48 [debug] 30743#30743: *162 test location: "/" 2016/11/15 19:11:48 [debug] 30743#30743: *162 test location: "docs/" 2016/11/15 19:11:48 [debug] 30743#30743: *162 test location: "appname/socket" 2016/11/15 19:11:48 [debug] 30743#30743: *162 test location: ~ "^/(index.html)?$" 2016/11/15 19:11:48 [debug] 30743#30743: *162 test location: ~ "^/login/?$" 2016/11/15 19:11:48 [debug] 30743#30743: *162 test location: ~ "^/(appname)" 2016/11/15 19:11:48 [debug] 30743#30743: *162 test location: ~ "/components/(.*)" 2016/11/15 19:11:48 [debug] 30743#30743: *162 test location: ~ "^/(auth|logout|status|widgetTypes|index.appname.html|login.appname.html|favicon.ico|(.*)\/vendor\/flags\/.*\.(?:jpg|png)|(.*)\/assets\/images\/company_logo.png)$" 2016/11/15 19:11:48 [debug] 30743#30743: *162 using configuration "/" 2016/11/15 19:11:48 [debug] 30743#30743: *162 http cl:26568 max:1073741824 2016/11/15 19:11:48 [debug] 30743#30743: *162 rewrite phase: 3 2016/11/15 19:11:48 [debug] 30743#30743: *162 post rewrite phase: 4 2016/11/15 19:11:48 [debug] 30743#30743: *162 generic phase: 5 2016/11/15 19:11:48 [debug] 30743#30743: *162 generic phase: 6 2016/11/15 19:11:48 [debug] 30743#30743: *162 generic phase: 7 2016/11/15 19:11:48 [debug] 30743#30743: *162 access phase: 8 2016/11/15 19:11:48 [debug] 30743#30743: *162 access phase: 9 2016/11/15 19:11:48 [debug] 30743#30743: *162 access phase: 10 2016/11/15 19:11:48 [debug] 30743#30743: *162 auth request handler 2016/11/15 19:11:48 [debug] 30743#30743: *162 posix_memalign: 00000F0D34EB6570:4096 @16 2016/11/15 19:11:48 [debug] 30743#30743: *162 http subrequest "/authorize?" 2016/11/15 19:11:48 [debug] 30743#30743: *162 http posted request: "/authorize?" 2016/11/15 19:11:48 [debug] 30743#30743: *162 rewrite phase: 1 2016/11/15 19:11:48 [debug] 30743#30743: *162 test location: "^/widgets/$" 2016/11/15 19:11:48 [debug] 30743#30743: *162 test location: "/" 2016/11/15 19:11:48 [debug] 30743#30743: *162 test location: "docs/" 2016/11/15 19:11:48 [debug] 30743#30743: *162 test location: "dashboard" 2016/11/15 19:11:48 [debug] 30743#30743: *162 test location: "authorize" 2016/11/15 19:11:48 [debug] 30743#30743: *162 using configuration "=/authorize" 2016/11/15 19:11:48 [debug] 30743#30743: *162 http cl:26568 max:1073741824 2016/11/15 19:11:48 [debug] 30743#30743: *162 rewrite phase: 3 2016/11/15 19:11:48 [debug] 30743#30743: *162 post rewrite phase: 4 2016/11/15 19:11:48 [debug] 30743#30743: *162 generic phase: 5 2016/11/15 19:11:48 [debug] 30743#30743: *162 generic phase: 6 2016/11/15 19:11:48 [debug] 30743#30743: *162 generic phase: 7 2016/11/15 19:11:48 [debug] 30743#30743: *162 http init upstream, client timer: 0 2016/11/15 19:11:48 [debug] 30743#30743: *162 posix_memalign: 00000F0D34EB7580:4096 @16 2016/11/15 19:11:48 [debug] 30743#30743: *162 http script copy: "X-Real-IP: " 2016/11/15 19:11:48 [debug] 30743#30743: *162 http script var: "192.168.123.11" 2016/11/15 19:11:48 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:48 [debug] 30743#30743: *162 http script copy: "X-Forwarded-For: " 2016/11/15 19:11:48 [debug] 30743#30743: *162 http script var: "192.168.123.11" 2016/11/15 19:11:48 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:48 [debug] 30743#30743: *162 http script copy: "Host: " 2016/11/15 19:11:48 [debug] 30743#30743: *162 http script var: "app3.mydomain.local" 2016/11/15 19:11:48 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:48 [debug] 30743#30743: *162 http script copy: "X-NginX-Proxy: true " 2016/11/15 19:11:48 [debug] 30743#30743: *162 http script copy: "X-Client-S-DN: " 2016/11/15 19:11:48 [debug] 30743#30743: *162 http script var: "XXX" 2016/11/15 19:11:48 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:48 [debug] 30743#30743: *162 http script copy: "X-Client-Serial: " 2016/11/15 19:11:48 [debug] 30743#30743: *162 http script var: "XXXX" 2016/11/15 19:11:48 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:48 [debug] 30743#30743: *162 http script copy: "x-appname-uri: " 2016/11/15 19:11:48 [debug] 30743#30743: *162 http script var: "/appname/v2/heartbeat" 2016/11/15 19:11:48 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:48 [debug] 30743#30743: *162 http script copy: "x-appname-method: " 2016/11/15 19:11:48 [debug] 30743#30743: *162 http script var: "POST" 2016/11/15 19:11:48 [debug] 30743#30743: *162 http script copy: " " 2016/11/15 19:11:48 [debug] 30743#30743: *162 http script copy: "Connection: close " 2016/11/15 19:11:48 [debug] 30743#30743: *162 http script copy: "" 2016/11/15 19:11:48 [debug] 30743#30743: *162 http script copy: "" 2016/11/15 19:11:48 [debug] 30743#30743: *162 http proxy header: "accept: application/json, text/plain, */*" 2016/11/15 19:11:48 [debug] 30743#30743: *162 http proxy header: "origin: https://app3.mydomain.local" 2016/11/15 19:11:48 [debug] 30743#30743: *162 http proxy header: "appname-csrf-token: YYY 2016/11/15 19:11:48 [debug] 30743#30743: *162 http proxy header: "user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.75 Safari/537.36" 2016/11/15 19:11:48 [debug] 30743#30743: *162 http proxy header: "content-type: application/json;charset=UTF-8" 2016/11/15 19:11:48 [debug] 30743#30743: *162 http proxy header: "accept-encoding: gzip, deflate, br" 2016/11/15 19:11:48 [debug] 30743#30743: *162 http proxy header: "accept-language: en-US,en;q=0.8" 2016/11/15 19:11:48 [debug] 30743#30743: *162 http proxy header: "cookie: XXX" 2016/11/15 19:11:48 [debug] 30743#30743: *162 http proxy header: "GET /authorize HTTP/1.1 X-Real-IP: 192.168.123.11 X-Forwarded-For: 192.168.123.11 Host: app3.mydomain.local X-NginX-Proxy: true x-appname-uri: /appname/v2/heartbeat x-appname-method: POST Connection: close accept: application/json, text/plain, */* origin: https://app3.mydomain.local appname-csrf-token: YYY user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.75 Safari/537.36 content-type: application/json;charset=UTF-8 accept-encoding: gzip, deflate, br accept-language: en-US,en;q=0.8