2016/11/15 19:11:48 [debug] 30743#30743: *162 http cleanup add: 00000F0D34E64460
2016/11/15 19:11:48 [debug] 30743#30743: *162 get rr peer, try: 1
2016/11/15 19:11:48 [debug] 30743#30743: *162 stream socket 7
2016/11/15 19:11:48 [debug] 30743#30743: *162 epoll add connection: fd:7 ev:80002005
2016/11/15 19:11:48 [debug] 30743#30743: *162 connect to 127.0.0.1:8008, fd:7 #573
2016/11/15 19:11:48 [debug] 30743#30743: *162 http upstream connect: -2
2016/11/15 19:11:48 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBBA30:128 @16
2016/11/15 19:11:48 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237168493
2016/11/15 19:11:48 [debug] 30743#30743: *162 http finalize request: -4, "/authorize?" a:1, c:3
2016/11/15 19:11:48 [debug] 30743#30743: *162 http request count:3 blk:0
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AC098 end:00006EFC4F5AED4C
2016/11/15 19:11:48 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:431
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:11:48 [debug] 30743#30743: *162 malloc: 00000F0D34D89720:65536
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5ACBC5 end:00006EFC4F5AED4C
2016/11/15 19:11:48 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:431
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AD6F2 end:00006EFC4F5AED4C
2016/11/15 19:11:48 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:431
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AE21F end:00006EFC4F5AED4C
2016/11/15 19:11:48 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:431
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AED4C end:00006EFC4F5AED4C
2016/11/15 19:11:48 [debug] 30743#30743: *162 event timer del: 3: 1479237278599
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 write handler
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: 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:0 f:0 l:2852 sid:431
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5ACB3D end:00006EFC4F5AECC4
2016/11/15 19:11:48 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:431
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AD66A end:00006EFC4F5AECC4
2016/11/15 19:11:48 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:431
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AE197 end:00006EFC4F5AECC4
2016/11/15 19:11:48 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:431
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AECC4 end:00006EFC4F5AECC4
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 write handler
2016/11/15 19:11:48 [debug] 30743#30743: *162 http upstream request: "/authorize?"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http upstream send request handler
2016/11/15 19:11:48 [debug] 30743#30743: *162 http upstream send request
2016/11/15 19:11:48 [debug] 30743#30743: *162 http upstream send request body
2016/11/15 19:11:48 [debug] 30743#30743: *162 chain writer buf fl:1 s:2711
2016/11/15 19:11:48 [debug] 30743#30743: *162 chain writer in: 00000F0D34EB7550
2016/11/15 19:11:48 [debug] 30743#30743: *162 writev: 2711 of 2711
2016/11/15 19:11:48 [debug] 30743#30743: *162 chain writer out: 0000000000000000
2016/11/15 19:11:48 [debug] 30743#30743: *162 event timer del: 7: 1479237168493
2016/11/15 19:11:48 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237168495
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: 2861
2016/11/15 19:11:48 [debug] 30743#30743: *162 SSL_read: 909
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:0 f:0 l:2852 sid:431
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5ACB3D end:00006EFC4F5ACECA
2016/11/15 19:11:48 [debug] 30743#30743: *162 process http2 frame type:0 f:1 l:900 sid:431
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5ACECA end:00006EFC4F5ACECA
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 write handler
2016/11/15 19:11:48 [debug] 30743#30743: *162 http upstream request: "/authorize?"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http upstream process header
2016/11/15 19:11:48 [debug] 30743#30743: *162 malloc: 00000F0D34DBC950:4096
2016/11/15 19:11:48 [debug] 30743#30743: *162 recv: fd:7 172 of 4096
2016/11/15 19:11:48 [debug] 30743#30743: *162 http proxy status 200 "200 OK"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http proxy header: "X-Powered-By: Express"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http proxy header: "x-appname-origin: appname3"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http proxy header: "content-type: application/json"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http proxy header: "content-length: 0"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http proxy header: "Date: Tue, 15 Nov 2016 19:11:48 GMT"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http proxy header: "Connection: close"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http proxy header done
2016/11/15 19:11:48 [debug] 30743#30743: *162 lua capture header filter, uri "/authorize"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 header filter
2016/11/15 19:11:48 [debug] 30743#30743: *162 finalize http upstream request: 0
2016/11/15 19:11:48 [debug] 30743#30743: *162 finalize http proxy request
2016/11/15 19:11:48 [debug] 30743#30743: *162 free rr peer 1 0
2016/11/15 19:11:48 [debug] 30743#30743: *162 close http upstream connection: 7
2016/11/15 19:11:48 [debug] 30743#30743: *162 free: 00000F0D34DBBA30, unused: 48
2016/11/15 19:11:48 [debug] 30743#30743: *162 event timer del: 7: 1479237168495
2016/11/15 19:11:48 [debug] 30743#30743: *162 reusable connection: 0
2016/11/15 19:11:48 [debug] 30743#30743: *162 http finalize request: 0, "/authorize?" a:1, c:2
2016/11/15 19:11:48 [debug] 30743#30743: *162 auth request done s:200
2016/11/15 19:11:48 [debug] 30743#30743: *162 http wake parent request: "/appname/v2/heartbeat?"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http posted request: "/appname/v2/heartbeat?"
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 auth request set variables
2016/11/15 19:11:48 [debug] 30743#30743: *162 access phase: 11
2016/11/15 19:11:48 [debug] 30743#30743: *162 lua access handler, uri:"/appname/v2/heartbeat" c:1
2016/11/15 19:11:48 [debug] 30743#30743: *162 post access phase: 12
2016/11/15 19:11:48 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBD960:4096 @16
2016/11/15 19:11:48 [debug] 30743#30743: *162 http body new buf t:1 f:0 00000F0D34D89720, pos 00000F0D34D89720, size: 26568 file: 0, size: 0
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 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: "Connection: close
"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http script copy: "Content-Length: "
2016/11/15 19:11:48 [debug] 30743#30743: *162 http script var: "26568"
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 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:
"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: 26568
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:48 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBE970:4096 @16
2016/11/15 19:11:48 [debug] 30743#30743: *162 http cleanup add: 00000F0D34DBE938
2016/11/15 19:11:48 [debug] 30743#30743: *162 get rr peer, try: 1
2016/11/15 19:11:48 [debug] 30743#30743: *162 stream socket 7
2016/11/15 19:11:48 [debug] 30743#30743: *162 epoll add connection: fd:7 ev:80002005
2016/11/15 19:11:48 [debug] 30743#30743: *162 connect to 182.168.128.69:8080, fd:7 #574
2016/11/15 19:11:48 [debug] 30743#30743: *162 http upstream connect: -2
2016/11/15 19:11:48 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBBA30:128 @16
2016/11/15 19:11:48 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237168525
2016/11/15 19:11:48 [debug] 30743#30743: *162 free: 00000F0D34D89720
2016/11/15 19:11:48 [debug] 30743#30743: *162 http finalize request: -4, "/appname/v2/heartbeat?" a:1, c:2
2016/11/15 19:11:48 [debug] 30743#30743: *162 http request count:2 blk:0
2016/11/15 19:11:48 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http upstream send request handler
2016/11/15 19:11:48 [debug] 30743#30743: *162 http upstream send request
2016/11/15 19:11:48 [debug] 30743#30743: *162 http upstream send request body
2016/11/15 19:11:48 [debug] 30743#30743: *162 chain writer buf fl:0 s:2690
2016/11/15 19:11:48 [debug] 30743#30743: *162 chain writer buf fl:1 s:26568
2016/11/15 19:11:48 [debug] 30743#30743: *162 chain writer in: 00000F0D34DBEA00
2016/11/15 19:11:48 [debug] 30743#30743: *162 writev: 28960 of 29258
2016/11/15 19:11:48 [debug] 30743#30743: *162 chain writer out: 00000F0D34DBEA10
2016/11/15 19:11:48 [debug] 30743#30743: *162 event timer: 7, old: 1479237168525, new: 1479237168526
2016/11/15 19:11:48 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http upstream send request handler
2016/11/15 19:11:48 [debug] 30743#30743: *162 http upstream send request
2016/11/15 19:11:48 [debug] 30743#30743: *162 http upstream send request body
2016/11/15 19:11:48 [debug] 30743#30743: *162 chain writer in: 00000F0D34DBEA10
2016/11/15 19:11:48 [debug] 30743#30743: *162 writev: 298 of 298
2016/11/15 19:11:48 [debug] 30743#30743: *162 chain writer out: 0000000000000000
2016/11/15 19:11:48 [debug] 30743#30743: *162 event timer del: 7: 1479237168525
2016/11/15 19:11:48 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237168527
2016/11/15 19:11:48 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http upstream process header
2016/11/15 19:11:48 [debug] 30743#30743: *162 malloc: 00000F0D34D69D00:4096
2016/11/15 19:11:48 [debug] 30743#30743: *162 recv: fd:7 1056 of 4096
2016/11/15 19:11:48 [debug] 30743#30743: *162 http proxy status 400 "400 Bad Request"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http proxy header: "Server: nginx"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http proxy header: "Date: Tue, 15 Nov 2016 19:11:48 GMT"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http proxy header: "Content-Type: text/html; charset=utf-8"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http proxy header: "Content-Length: 840"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http proxy header: "Connection: close"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http proxy header: "X-Powered-By: Express"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http proxy header: "X-Content-Type-Options: nosniff"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http proxy header done
2016/11/15 19:11:48 [debug] 30743#30743: *162 lua capture header filter, uri "/appname/v2/heartbeat"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 header filter
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 output header: ":status: 400"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 output header: "server: nginx"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 output header: "date: Tue, 15 Nov 2016 19:11:48 GMT"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 output header: "content-type: text/html; charset=utf-8"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 output header: "content-length: 840"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 output header: "x-powered-by: Express"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 output header: "x-content-type-options: nosniff"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2:431 create HEADERS frame 00000F0D34DBEDA8: len:98
2016/11/15 19:11:48 [debug] 30743#30743: *162 http cleanup add: 00000F0D34DBEE90
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 frame out: 00000F0D34DBEDA8 sid:431 bl:1 len:98
2016/11/15 19:11:48 [debug] 30743#30743: *162 malloc: 00000F0D34D83A10:16384
2016/11/15 19:11:48 [debug] 30743#30743: *162 SSL buf copy: 9
2016/11/15 19:11:48 [debug] 30743#30743: *162 SSL buf copy: 98
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2:431 HEADERS frame 00000F0D34DBEDA8 was sent
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 frame sent: 00000F0D34DBEDA8 sid:431 bl:1 len:98
2016/11/15 19:11:48 [debug] 30743#30743: *162 http cacheable: 0
2016/11/15 19:11:48 [debug] 30743#30743: *162 http proxy filter init s:400 h:0 c:0 l:840
2016/11/15 19:11:48 [debug] 30743#30743: *162 http upstream process upstream
2016/11/15 19:11:48 [debug] 30743#30743: *162 pipe read upstream: 1
2016/11/15 19:11:48 [debug] 30743#30743: *162 pipe preread: 840
2016/11/15 19:11:48 [debug] 30743#30743: *162 readv: 1, last:3040
2016/11/15 19:11:48 [debug] 30743#30743: *162 pipe recv chain: 0
2016/11/15 19:11:48 [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:48 [debug] 30743#30743: *162 pipe length: 840
2016/11/15 19:11:48 [debug] 30743#30743: *162 input buf #0
2016/11/15 19:11:48 [debug] 30743#30743: *162 pipe write downstream: 1
2016/11/15 19:11:48 [debug] 30743#30743: *162 pipe write downstream flush in
2016/11/15 19:11:48 [debug] 30743#30743: *162 http output filter "/appname/v2/heartbeat?"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http copy filter: "/appname/v2/heartbeat?"
2016/11/15 19:11:48 [debug] 30743#30743: *162 lua capture body filter, uri "/appname/v2/heartbeat"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http postpone filter "/appname/v2/heartbeat?" 00000F0D34DBEA00
2016/11/15 19:11:48 [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:48 [debug] 30743#30743: *162 http write filter: l:0 f:0 s:840
2016/11/15 19:11:48 [debug] 30743#30743: *162 http copy filter: 0 "/appname/v2/heartbeat?"
2016/11/15 19:11:48 [debug] 30743#30743: *162 pipe write downstream done
2016/11/15 19:11:48 [debug] 30743#30743: *162 event timer: 7, old: 1479237168527, new: 1479237168546
2016/11/15 19:11:48 [debug] 30743#30743: *162 http upstream exit: 0000000000000000
2016/11/15 19:11:48 [debug] 30743#30743: *162 finalize http upstream request: 0
2016/11/15 19:11:48 [debug] 30743#30743: *162 finalize http proxy request
2016/11/15 19:11:48 [debug] 30743#30743: *162 free rr peer 1 0
2016/11/15 19:11:48 [debug] 30743#30743: *162 close http upstream connection: 7
2016/11/15 19:11:48 [debug] 30743#30743: *162 free: 00000F0D34DBBA30, unused: 48
2016/11/15 19:11:48 [debug] 30743#30743: *162 event timer del: 7: 1479237168527
2016/11/15 19:11:48 [debug] 30743#30743: *162 reusable connection: 0
2016/11/15 19:11:48 [debug] 30743#30743: *162 http upstream temp fd: -1
2016/11/15 19:11:48 [debug] 30743#30743: *162 http output filter "/appname/v2/heartbeat?"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http copy filter: "/appname/v2/heartbeat?"
2016/11/15 19:11:48 [debug] 30743#30743: *162 lua capture body filter, uri "/appname/v2/heartbeat"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http postpone filter "/appname/v2/heartbeat?" 00007A9E70E05A50
2016/11/15 19:11:48 [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:48 [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:48 [debug] 30743#30743: *162 http write filter: l:1 f:0 s:840
2016/11/15 19:11:48 [debug] 30743#30743: *162 http write filter limit 0
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2:431 create DATA frame 00000F0D34DBEDA8: len:840 flags:1
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 frame out: 00000F0D34DBEDA8 sid:431 bl:0 len:840
2016/11/15 19:11:48 [debug] 30743#30743: *162 SSL buf copy: 9
2016/11/15 19:11:48 [debug] 30743#30743: *162 SSL buf copy: 840
2016/11/15 19:11:48 [debug] 30743#30743: *162 SSL to write: 956
2016/11/15 19:11:48 [debug] 30743#30743: *162 SSL_write: 956
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2:431 DATA frame 00000F0D34DBEDA8 was sent
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 frame sent: 00000F0D34DBEDA8 sid:431 bl:0 len:840
2016/11/15 19:11:48 [debug] 30743#30743: *162 http write filter 0000000000000000
2016/11/15 19:11:48 [debug] 30743#30743: *162 http copy filter: 0 "/appname/v2/heartbeat?"
2016/11/15 19:11:48 [debug] 30743#30743: *162 http finalize request: 0, "/appname/v2/heartbeat?" a:1, c:1
2016/11/15 19:11:48 [debug] 30743#30743: *162 http request count:1 blk:0
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 close stream 431, queued 0, processing 1
2016/11/15 19:11:48 [debug] 30743#30743: *162 http close request
2016/11/15 19:11:48 [debug] 30743#30743: *162 http log handler
2016/11/15 19:11:48 [debug] 30743#30743: *162 free: 00000F0D34DBC950
2016/11/15 19:11:48 [debug] 30743#30743: *162 free: 00000F0D34D69D00
2016/11/15 19:11:48 [debug] 30743#30743: *162 free: 00000F0D34E120F0, unused: 0
2016/11/15 19:11:48 [debug] 30743#30743: *162 free: 00000F0D34E63480, unused: 2
2016/11/15 19:11:48 [debug] 30743#30743: *162 free: 00000F0D34EB6570, unused: 0
2016/11/15 19:11:48 [debug] 30743#30743: *162 free: 00000F0D34EB7580, unused: 8
2016/11/15 19:11:48 [debug] 30743#30743: *162 free: 00000F0D34DBD960, unused: 0
2016/11/15 19:11:48 [debug] 30743#30743: *162 free: 00000F0D34DBE970, unused: 1926
2016/11/15 19:11:48 [debug] 30743#30743: *162 free: 00000F0D34E61530, unused: 149
2016/11/15 19:11:48 [debug] 30743#30743: *162 free: 00000F0D34E16F00, unused: 156
2016/11/15 19:11:48 [debug] 30743#30743: *162 free: 00000F0D34DC4930, unused: 111
2016/11/15 19:11:48 [debug] 30743#30743: *162 post event 00006EFC4C5081F0
2016/11/15 19:11:48 [debug] 30743#30743: *162 delete posted event 00006EFC4C5081F0
2016/11/15 19:11:48 [debug] 30743#30743: *162 http2 handle connection handler
2016/11/15 19:11:48 [debug] 30743#30743: *162 free: 00000F0D34E03BC0, unused: 3488
2016/11/15 19:11:48 [debug] 30743#30743: *162 free: 00000F0D34D83A10
2016/11/15 19:11:48 [debug] 30743#30743: *162 reusable connection: 1
2016/11/15 19:11:48 [debug] 30743#30743: *162 event timer add: 3: 180000:1479237288546
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 idle handler
2016/11/15 19:11:50 [debug] 30743#30743: *162 reusable connection: 0
2016/11/15 19:11:50 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E120F0:4096 @16
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 read handler
2016/11/15 19:11:50 [debug] 30743#30743: *162 SSL_read: 55
2016/11/15 19:11:50 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:11:50 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:11:50 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:11:50 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:11:50 [debug] 30743#30743: *162 SSL_read: -1
2016/11/15 19:11:50 [debug] 30743#30743: *162 SSL_get_error: 2
2016/11/15 19:11:50 [debug] 30743#30743: *162 process http2 frame type:1 f:24 l:46 sid:433
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 HEADERS frame sid:433 on 0 excl:0 weight:183
2016/11/15 19:11:50 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DC4930:1024 @16
2016/11/15 19:11:50 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E03BC0:4096 @16
2016/11/15 19:11:50 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E63480:4096 @16
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 get indexed header name: 3
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 get indexed header name: 68
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 get indexed header name: 7
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 hpack encoded string length: 4
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 hpack encoded string length: 13
2016/11/15 19:11:50 [debug] 30743#30743: *162 http uri: "/appname/v2/heartbeat"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http args: ""
2016/11/15 19:11:50 [debug] 30743#30743: *162 http exten: ""
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 get indexed header: 28
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 hpack encoded string length: 4
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 add header to hpack table: "content-length: 16595"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 hpack table account: 51 free:177
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 http header: "content-length: 16595"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 get indexed header name: 67
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 http header: "accept: application/json, text/plain, */*"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 get indexed header name: 79
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 http header: "origin: https://app3.mydomain.local"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 get indexed header name: 95
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 http header: "appname-csrf-token: YYY
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 get indexed header name: 63
2016/11/15 19:11:50 [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:50 [debug] 30743#30743: *162 http2 get indexed header name: 78
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 http header: "content-type: application/json;charset=UTF-8"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 get indexed header name: 76
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 http header: "accept-encoding: gzip, deflate, br"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 get indexed header name: 92
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 http header: "accept-language: en-US,en;q=0.8"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 get indexed header name: 91
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 get indexed header name: 90
2016/11/15 19:11:50 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E16F00:1024 @16
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 get indexed header name: 89
2016/11/15 19:11:50 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E61530:1024 @16
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 get indexed header name: 88
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 get indexed header name: 94
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 http request line: "POST /appname/v2/heartbeat HTTP/2.0"
2016/11/15 19:11:50 [debug] 30743#30743: *162 generic phase: 0
2016/11/15 19:11:50 [debug] 30743#30743: *162 rewrite phase: 1
2016/11/15 19:11:50 [debug] 30743#30743: *162 test location: "^/widgets/$"
2016/11/15 19:11:50 [debug] 30743#30743: *162 test location: "/"
2016/11/15 19:11:50 [debug] 30743#30743: *162 test location: "docs/"
2016/11/15 19:11:50 [debug] 30743#30743: *162 test location: "appname/socket"
2016/11/15 19:11:50 [debug] 30743#30743: *162 test location: ~ "^/(index.html)?$"
2016/11/15 19:11:50 [debug] 30743#30743: *162 test location: ~ "^/login/?$"
2016/11/15 19:11:50 [debug] 30743#30743: *162 test location: ~ "^/(appname)"
2016/11/15 19:11:50 [debug] 30743#30743: *162 test location: ~ "/components/(.*)"
2016/11/15 19:11:50 [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:50 [debug] 30743#30743: *162 using configuration "/"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http cl:16595 max:1073741824
2016/11/15 19:11:50 [debug] 30743#30743: *162 rewrite phase: 3
2016/11/15 19:11:50 [debug] 30743#30743: *162 post rewrite phase: 4
2016/11/15 19:11:50 [debug] 30743#30743: *162 generic phase: 5
2016/11/15 19:11:50 [debug] 30743#30743: *162 generic phase: 6
2016/11/15 19:11:50 [debug] 30743#30743: *162 generic phase: 7
2016/11/15 19:11:50 [debug] 30743#30743: *162 access phase: 8
2016/11/15 19:11:50 [debug] 30743#30743: *162 access phase: 9
2016/11/15 19:11:50 [debug] 30743#30743: *162 access phase: 10
2016/11/15 19:11:50 [debug] 30743#30743: *162 auth request handler
2016/11/15 19:11:50 [debug] 30743#30743: *162 posix_memalign: 00000F0D34EB6570:4096 @16
2016/11/15 19:11:50 [debug] 30743#30743: *162 http subrequest "/authorize?"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http posted request: "/authorize?"
2016/11/15 19:11:50 [debug] 30743#30743: *162 rewrite phase: 1
2016/11/15 19:11:50 [debug] 30743#30743: *162 test location: "^/widgets/$"
2016/11/15 19:11:50 [debug] 30743#30743: *162 test location: "/"
2016/11/15 19:11:50 [debug] 30743#30743: *162 test location: "docs/"
2016/11/15 19:11:50 [debug] 30743#30743: *162 test location: "dashboard"
2016/11/15 19:11:50 [debug] 30743#30743: *162 test location: "authorize"
2016/11/15 19:11:50 [debug] 30743#30743: *162 using configuration "=/authorize"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http cl:16595 max:1073741824
2016/11/15 19:11:50 [debug] 30743#30743: *162 rewrite phase: 3
2016/11/15 19:11:50 [debug] 30743#30743: *162 post rewrite phase: 4
2016/11/15 19:11:50 [debug] 30743#30743: *162 generic phase: 5
2016/11/15 19:11:50 [debug] 30743#30743: *162 generic phase: 6
2016/11/15 19:11:50 [debug] 30743#30743: *162 generic phase: 7
2016/11/15 19:11:50 [debug] 30743#30743: *162 http init upstream, client timer: 0
2016/11/15 19:11:50 [debug] 30743#30743: *162 posix_memalign: 00000F0D34EB7580:4096 @16
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: "X-Real-IP: "
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script var: "192.168.123.11"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: "X-Forwarded-For: "
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script var: "192.168.123.11"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: "Host: "
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script var: "app3.mydomain.local"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: "X-NginX-Proxy: true
"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: "X-Client-S-DN: "
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script var: "XXX"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: "X-Client-Serial: "
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script var: "XXXX"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: "x-appname-uri: "
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script var: "/appname/v2/heartbeat"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: "x-appname-method: "
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script var: "POST"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: "Connection: close
"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: ""
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: ""
2016/11/15 19:11:50 [debug] 30743#30743: *162 http proxy header: "accept: application/json, text/plain, */*"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http proxy header: "origin: https://app3.mydomain.local"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http proxy header: "appname-csrf-token: YYY
2016/11/15 19:11:50 [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:50 [debug] 30743#30743: *162 http proxy header: "content-type: application/json;charset=UTF-8"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http proxy header: "accept-encoding: gzip, deflate, br"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http proxy header: "accept-language: en-US,en;q=0.8"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http proxy header: "cookie: XXX"
2016/11/15 19:11:50 [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:50 [debug] 30743#30743: *162 http cleanup add: 00000F0D34E64460
2016/11/15 19:11:50 [debug] 30743#30743: *162 get rr peer, try: 1
2016/11/15 19:11:50 [debug] 30743#30743: *162 stream socket 7
2016/11/15 19:11:50 [debug] 30743#30743: *162 epoll add connection: fd:7 ev:80002005
2016/11/15 19:11:50 [debug] 30743#30743: *162 connect to 127.0.0.1:8008, fd:7 #575
2016/11/15 19:11:50 [debug] 30743#30743: *162 http upstream connect: -2
2016/11/15 19:11:50 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBBA30:128 @16
2016/11/15 19:11:50 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237170563
2016/11/15 19:11:50 [debug] 30743#30743: *162 http finalize request: -4, "/authorize?" a:1, c:3
2016/11/15 19:11:50 [debug] 30743#30743: *162 http request count:3 blk:0
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AC047 end:00006EFC4F5AECFB
2016/11/15 19:11:50 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:433
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:11:50 [debug] 30743#30743: *162 malloc: 00000F0D34D89720:65536
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5ACB74 end:00006EFC4F5AECFB
2016/11/15 19:11:50 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:433
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AD6A1 end:00006EFC4F5AECFB
2016/11/15 19:11:50 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:433
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AE1CE end:00006EFC4F5AECFB
2016/11/15 19:11:50 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:433
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AECFB end:00006EFC4F5AECFB
2016/11/15 19:11:50 [debug] 30743#30743: *162 event timer del: 3: 1479237288546
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 write handler
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 read handler
2016/11/15 19:11:50 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:11:50 [debug] 30743#30743: *162 SSL_read: 2344
2016/11/15 19:11:50 [debug] 30743#30743: *162 SSL_read: -1
2016/11/15 19:11:50 [debug] 30743#30743: *162 SSL_get_error: 2
2016/11/15 19:11:50 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:433
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5ACB3D end:00006EFC4F5AD465
2016/11/15 19:11:50 [debug] 30743#30743: *162 process http2 frame type:0 f:1 l:2335 sid:433
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AD465 end:00006EFC4F5AD465
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 write handler
2016/11/15 19:11:50 [debug] 30743#30743: *162 http upstream request: "/authorize?"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http upstream send request handler
2016/11/15 19:11:50 [debug] 30743#30743: *162 http upstream send request
2016/11/15 19:11:50 [debug] 30743#30743: *162 http upstream send request body
2016/11/15 19:11:50 [debug] 30743#30743: *162 chain writer buf fl:1 s:2711
2016/11/15 19:11:50 [debug] 30743#30743: *162 chain writer in: 00000F0D34EB7550
2016/11/15 19:11:50 [debug] 30743#30743: *162 writev: 2711 of 2711
2016/11/15 19:11:50 [debug] 30743#30743: *162 chain writer out: 0000000000000000
2016/11/15 19:11:50 [debug] 30743#30743: *162 event timer del: 7: 1479237170563
2016/11/15 19:11:50 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237170564
2016/11/15 19:11:50 [debug] 30743#30743: *162 http upstream request: "/authorize?"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http upstream process header
2016/11/15 19:11:50 [debug] 30743#30743: *162 malloc: 00000F0D34DBC950:4096
2016/11/15 19:11:50 [debug] 30743#30743: *162 recv: fd:7 172 of 4096
2016/11/15 19:11:50 [debug] 30743#30743: *162 http proxy status 200 "200 OK"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http proxy header: "X-Powered-By: Express"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http proxy header: "x-appname-origin: appname3"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http proxy header: "content-type: application/json"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http proxy header: "content-length: 0"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http proxy header: "Date: Tue, 15 Nov 2016 19:11:50 GMT"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http proxy header: "Connection: close"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http proxy header done
2016/11/15 19:11:50 [debug] 30743#30743: *162 lua capture header filter, uri "/authorize"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 header filter
2016/11/15 19:11:50 [debug] 30743#30743: *162 finalize http upstream request: 0
2016/11/15 19:11:50 [debug] 30743#30743: *162 finalize http proxy request
2016/11/15 19:11:50 [debug] 30743#30743: *162 free rr peer 1 0
2016/11/15 19:11:50 [debug] 30743#30743: *162 close http upstream connection: 7
2016/11/15 19:11:50 [debug] 30743#30743: *162 free: 00000F0D34DBBA30, unused: 48
2016/11/15 19:11:50 [debug] 30743#30743: *162 event timer del: 7: 1479237170564
2016/11/15 19:11:50 [debug] 30743#30743: *162 reusable connection: 0
2016/11/15 19:11:50 [debug] 30743#30743: *162 http finalize request: 0, "/authorize?" a:1, c:2
2016/11/15 19:11:50 [debug] 30743#30743: *162 auth request done s:200
2016/11/15 19:11:50 [debug] 30743#30743: *162 http wake parent request: "/appname/v2/heartbeat?"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http posted request: "/appname/v2/heartbeat?"
2016/11/15 19:11:50 [debug] 30743#30743: *162 access phase: 10
2016/11/15 19:11:50 [debug] 30743#30743: *162 auth request handler
2016/11/15 19:11:50 [debug] 30743#30743: *162 auth request set variables
2016/11/15 19:11:50 [debug] 30743#30743: *162 access phase: 11
2016/11/15 19:11:50 [debug] 30743#30743: *162 lua access handler, uri:"/appname/v2/heartbeat" c:1
2016/11/15 19:11:50 [debug] 30743#30743: *162 post access phase: 12
2016/11/15 19:11:50 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBD960:4096 @16
2016/11/15 19:11:50 [debug] 30743#30743: *162 http body new buf t:1 f:0 00000F0D34D89720, pos 00000F0D34D89720, size: 16595 file: 0, size: 0
2016/11/15 19:11:50 [debug] 30743#30743: *162 http init upstream, client timer: 0
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: "X-Real-IP: "
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script var: "192.168.123.11"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: "X-Forwarded-For: "
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script var: "192.168.123.11"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: "Host: "
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script var: "app3.mydomain.local"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: "X-NginX-Proxy: true
"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: "X-Client-S-DN: "
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script var: "XXX"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: "X-Client-Serial: "
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script var: "XXXX"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: "Connection: close
"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: "Content-Length: "
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script var: "16595"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: ""
2016/11/15 19:11:50 [debug] 30743#30743: *162 http script copy: ""
2016/11/15 19:11:50 [debug] 30743#30743: *162 http proxy header: "accept: application/json, text/plain, */*"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http proxy header: "origin: https://app3.mydomain.local"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http proxy header: "appname-csrf-token: YYY
2016/11/15 19:11:50 [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:50 [debug] 30743#30743: *162 http proxy header: "content-type: application/json;charset=UTF-8"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http proxy header: "accept-encoding: gzip, deflate, br"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http proxy header: "accept-language: en-US,en;q=0.8"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http proxy header: "cookie: XXX"
2016/11/15 19:11:50 [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: 16595
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:50 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBE970:4096 @16
2016/11/15 19:11:50 [debug] 30743#30743: *162 http cleanup add: 00000F0D34DBE938
2016/11/15 19:11:50 [debug] 30743#30743: *162 get rr peer, try: 1
2016/11/15 19:11:50 [debug] 30743#30743: *162 stream socket 7
2016/11/15 19:11:50 [debug] 30743#30743: *162 epoll add connection: fd:7 ev:80002005
2016/11/15 19:11:50 [debug] 30743#30743: *162 connect to 182.168.128.69:8080, fd:7 #576
2016/11/15 19:11:50 [debug] 30743#30743: *162 http upstream connect: -2
2016/11/15 19:11:50 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBBA30:128 @16
2016/11/15 19:11:50 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237170593
2016/11/15 19:11:50 [debug] 30743#30743: *162 free: 00000F0D34D89720
2016/11/15 19:11:50 [debug] 30743#30743: *162 http finalize request: -4, "/appname/v2/heartbeat?" a:1, c:2
2016/11/15 19:11:50 [debug] 30743#30743: *162 http request count:2 blk:0
2016/11/15 19:11:50 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http upstream send request handler
2016/11/15 19:11:50 [debug] 30743#30743: *162 http upstream send request
2016/11/15 19:11:50 [debug] 30743#30743: *162 http upstream send request body
2016/11/15 19:11:50 [debug] 30743#30743: *162 chain writer buf fl:0 s:2690
2016/11/15 19:11:50 [debug] 30743#30743: *162 chain writer buf fl:1 s:16595
2016/11/15 19:11:50 [debug] 30743#30743: *162 chain writer in: 00000F0D34DBEA00
2016/11/15 19:11:50 [debug] 30743#30743: *162 writev: 19285 of 19285
2016/11/15 19:11:50 [debug] 30743#30743: *162 chain writer out: 0000000000000000
2016/11/15 19:11:50 [debug] 30743#30743: *162 event timer del: 7: 1479237170593
2016/11/15 19:11:50 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237170594
2016/11/15 19:11:50 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http upstream process header
2016/11/15 19:11:50 [debug] 30743#30743: *162 malloc: 00000F0D34D69D00:4096
2016/11/15 19:11:50 [debug] 30743#30743: *162 recv: fd:7 1056 of 4096
2016/11/15 19:11:50 [debug] 30743#30743: *162 http proxy status 400 "400 Bad Request"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http proxy header: "Server: nginx"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http proxy header: "Date: Tue, 15 Nov 2016 19:11:48 GMT"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http proxy header: "Content-Type: text/html; charset=utf-8"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http proxy header: "Content-Length: 840"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http proxy header: "Connection: close"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http proxy header: "X-Powered-By: Express"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http proxy header: "X-Content-Type-Options: nosniff"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http proxy header done
2016/11/15 19:11:50 [debug] 30743#30743: *162 lua capture header filter, uri "/appname/v2/heartbeat"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 header filter
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 output header: ":status: 400"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 output header: "server: nginx"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 output header: "date: Tue, 15 Nov 2016 19:11:50 GMT"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 output header: "content-type: text/html; charset=utf-8"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 output header: "content-length: 840"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 output header: "x-powered-by: Express"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 output header: "x-content-type-options: nosniff"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2:433 create HEADERS frame 00000F0D34DBEDA8: len:98
2016/11/15 19:11:50 [debug] 30743#30743: *162 http cleanup add: 00000F0D34DBEE90
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 frame out: 00000F0D34DBEDA8 sid:433 bl:1 len:98
2016/11/15 19:11:50 [debug] 30743#30743: *162 malloc: 00000F0D34D83A10:16384
2016/11/15 19:11:50 [debug] 30743#30743: *162 SSL buf copy: 9
2016/11/15 19:11:50 [debug] 30743#30743: *162 SSL buf copy: 98
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2:433 HEADERS frame 00000F0D34DBEDA8 was sent
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 frame sent: 00000F0D34DBEDA8 sid:433 bl:1 len:98
2016/11/15 19:11:50 [debug] 30743#30743: *162 http cacheable: 0
2016/11/15 19:11:50 [debug] 30743#30743: *162 http proxy filter init s:400 h:0 c:0 l:840
2016/11/15 19:11:50 [debug] 30743#30743: *162 http upstream process upstream
2016/11/15 19:11:50 [debug] 30743#30743: *162 pipe read upstream: 1
2016/11/15 19:11:50 [debug] 30743#30743: *162 pipe preread: 840
2016/11/15 19:11:50 [debug] 30743#30743: *162 readv: 1, last:3040
2016/11/15 19:11:50 [debug] 30743#30743: *162 pipe recv chain: 0
2016/11/15 19:11:50 [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:50 [debug] 30743#30743: *162 pipe length: 840
2016/11/15 19:11:50 [debug] 30743#30743: *162 input buf #0
2016/11/15 19:11:50 [debug] 30743#30743: *162 pipe write downstream: 1
2016/11/15 19:11:50 [debug] 30743#30743: *162 pipe write downstream flush in
2016/11/15 19:11:50 [debug] 30743#30743: *162 http output filter "/appname/v2/heartbeat?"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http copy filter: "/appname/v2/heartbeat?"
2016/11/15 19:11:50 [debug] 30743#30743: *162 lua capture body filter, uri "/appname/v2/heartbeat"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http postpone filter "/appname/v2/heartbeat?" 00000F0D34DBEA00
2016/11/15 19:11:50 [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:50 [debug] 30743#30743: *162 http write filter: l:0 f:0 s:840
2016/11/15 19:11:50 [debug] 30743#30743: *162 http copy filter: 0 "/appname/v2/heartbeat?"
2016/11/15 19:11:50 [debug] 30743#30743: *162 pipe write downstream done
2016/11/15 19:11:50 [debug] 30743#30743: *162 event timer: 7, old: 1479237170594, new: 1479237170608
2016/11/15 19:11:50 [debug] 30743#30743: *162 http upstream exit: 0000000000000000
2016/11/15 19:11:50 [debug] 30743#30743: *162 finalize http upstream request: 0
2016/11/15 19:11:50 [debug] 30743#30743: *162 finalize http proxy request
2016/11/15 19:11:50 [debug] 30743#30743: *162 free rr peer 1 0
2016/11/15 19:11:50 [debug] 30743#30743: *162 close http upstream connection: 7
2016/11/15 19:11:50 [debug] 30743#30743: *162 free: 00000F0D34DBBA30, unused: 48
2016/11/15 19:11:50 [debug] 30743#30743: *162 event timer del: 7: 1479237170594
2016/11/15 19:11:50 [debug] 30743#30743: *162 reusable connection: 0
2016/11/15 19:11:50 [debug] 30743#30743: *162 http upstream temp fd: -1
2016/11/15 19:11:50 [debug] 30743#30743: *162 http output filter "/appname/v2/heartbeat?"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http copy filter: "/appname/v2/heartbeat?"
2016/11/15 19:11:50 [debug] 30743#30743: *162 lua capture body filter, uri "/appname/v2/heartbeat"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http postpone filter "/appname/v2/heartbeat?" 00007A9E70E05A50
2016/11/15 19:11:50 [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:50 [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:50 [debug] 30743#30743: *162 http write filter: l:1 f:0 s:840
2016/11/15 19:11:50 [debug] 30743#30743: *162 http write filter limit 0
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2:433 create DATA frame 00000F0D34DBEDA8: len:840 flags:1
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 frame out: 00000F0D34DBEDA8 sid:433 bl:0 len:840
2016/11/15 19:11:50 [debug] 30743#30743: *162 SSL buf copy: 9
2016/11/15 19:11:50 [debug] 30743#30743: *162 SSL buf copy: 840
2016/11/15 19:11:50 [debug] 30743#30743: *162 SSL to write: 956
2016/11/15 19:11:50 [debug] 30743#30743: *162 SSL_write: 956
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2:433 DATA frame 00000F0D34DBEDA8 was sent
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 frame sent: 00000F0D34DBEDA8 sid:433 bl:0 len:840
2016/11/15 19:11:50 [debug] 30743#30743: *162 http write filter 0000000000000000
2016/11/15 19:11:50 [debug] 30743#30743: *162 http copy filter: 0 "/appname/v2/heartbeat?"
2016/11/15 19:11:50 [debug] 30743#30743: *162 http finalize request: 0, "/appname/v2/heartbeat?" a:1, c:1
2016/11/15 19:11:50 [debug] 30743#30743: *162 http request count:1 blk:0
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 close stream 433, queued 0, processing 1
2016/11/15 19:11:50 [debug] 30743#30743: *162 http close request
2016/11/15 19:11:50 [debug] 30743#30743: *162 http log handler
2016/11/15 19:11:50 [debug] 30743#30743: *162 free: 00000F0D34DBC950
2016/11/15 19:11:50 [debug] 30743#30743: *162 free: 00000F0D34D69D00
2016/11/15 19:11:50 [debug] 30743#30743: *162 free: 00000F0D34E03BC0, unused: 0
2016/11/15 19:11:50 [debug] 30743#30743: *162 free: 00000F0D34E63480, unused: 2
2016/11/15 19:11:50 [debug] 30743#30743: *162 free: 00000F0D34EB6570, unused: 0
2016/11/15 19:11:50 [debug] 30743#30743: *162 free: 00000F0D34EB7580, unused: 8
2016/11/15 19:11:50 [debug] 30743#30743: *162 free: 00000F0D34DBD960, unused: 0
2016/11/15 19:11:50 [debug] 30743#30743: *162 free: 00000F0D34DBE970, unused: 1926
2016/11/15 19:11:50 [debug] 30743#30743: *162 free: 00000F0D34DC4930, unused: 162
2016/11/15 19:11:50 [debug] 30743#30743: *162 free: 00000F0D34E16F00, unused: 156
2016/11/15 19:11:50 [debug] 30743#30743: *162 free: 00000F0D34E61530, unused: 111
2016/11/15 19:11:50 [debug] 30743#30743: *162 post event 00006EFC4C5081F0
2016/11/15 19:11:50 [debug] 30743#30743: *162 delete posted event 00006EFC4C5081F0
2016/11/15 19:11:50 [debug] 30743#30743: *162 http2 handle connection handler
2016/11/15 19:11:50 [debug] 30743#30743: *162 free: 00000F0D34E120F0, unused: 3488
2016/11/15 19:11:50 [debug] 30743#30743: *162 free: 00000F0D34D83A10
2016/11/15 19:11:50 [debug] 30743#30743: *162 reusable connection: 1
2016/11/15 19:11:50 [debug] 30743#30743: *162 event timer add: 3: 180000:1479237290608
2016/11/15 19:11:57 [debug] 30741#30741: *300 post event 00006EFC4C5082B0
2016/11/15 19:11:57 [debug] 30741#30741: *300 post event 00006EFC4C2072B0
2016/11/15 19:11:57 [debug] 30741#30741: *300 delete posted event 00006EFC4C5082B0
2016/11/15 19:11:57 [debug] 30741#30741: *300 http run request: "/appname/socket/?EIO=3&transport=websocket&sid=fJvr3YafvdqAy4F3AAAC"
2016/11/15 19:11:57 [debug] 30741#30741: *300 http upstream process upgraded, fu:0
2016/11/15 19:11:57 [debug] 30741#30741: *300 SSL_read: 9
2016/11/15 19:11:57 [debug] 30741#30741: *300 SSL_read: -1
2016/11/15 19:11:57 [debug] 30741#30741: *300 SSL_get_error: 2
2016/11/15 19:11:57 [debug] 30741#30741: *300 send: fd:16 9 of 9
2016/11/15 19:11:57 [debug] 30741#30741: *300 event timer del: 16: 1479237151562
2016/11/15 19:11:57 [debug] 30741#30741: *300 event timer add: 16: 60000:1479237177561
2016/11/15 19:11:57 [debug] 30741#30741: *300 delete posted event 00006EFC4C2072B0
2016/11/15 19:11:57 [debug] 30741#30741: *300 http run request: "/appname/socket/?EIO=3&transport=websocket&sid=fJvr3YafvdqAy4F3AAAC"
2016/11/15 19:11:57 [debug] 30741#30741: *300 http upstream process upgraded, fu:1
2016/11/15 19:11:57 [debug] 30741#30741: *300 event timer: 16, old: 1479237177561, new: 1479237177561
2016/11/15 19:11:57 [debug] 30741#30741: *300 post event 00006EFC4C508310
2016/11/15 19:11:57 [debug] 30741#30741: *300 post event 00006EFC4C207310
2016/11/15 19:11:57 [debug] 30741#30741: *300 delete posted event 00006EFC4C508310
2016/11/15 19:11:57 [debug] 30741#30741: *300 http upstream request: "/appname/socket/?EIO=3&transport=websocket&sid=fJvr3YafvdqAy4F3AAAC"
2016/11/15 19:11:57 [debug] 30741#30741: *300 http upstream process upgraded, fu:1
2016/11/15 19:11:57 [debug] 30741#30741: *300 recv: fd:16 3 of 4096
2016/11/15 19:11:57 [debug] 30741#30741: *300 SSL to write: 3
2016/11/15 19:11:57 [debug] 30741#30741: *300 SSL_write: 3
2016/11/15 19:11:57 [debug] 30741#30741: *300 recv: fd:16 -1 of 4096
2016/11/15 19:11:57 [debug] 30741#30741: *300 recv() not ready (11: Resource temporarily unavailable)
2016/11/15 19:11:57 [debug] 30741#30741: *300 event timer: 16, old: 1479237177561, new: 1479237177563
2016/11/15 19:11:57 [debug] 30741#30741: *300 delete posted event 00006EFC4C207310
2016/11/15 19:11:57 [debug] 30741#30741: *300 http upstream request: "/appname/socket/?EIO=3&transport=websocket&sid=fJvr3YafvdqAy4F3AAAC"
2016/11/15 19:11:57 [debug] 30741#30741: *300 http upstream process upgraded, fu:0
2016/11/15 19:11:57 [debug] 30741#30741: *300 event timer: 16, old: 1479237177561, new: 1479237177563
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 idle handler
2016/11/15 19:11:58 [debug] 30743#30743: *162 reusable connection: 0
2016/11/15 19:11:58 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E03BC0:4096 @16
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 read handler
2016/11/15 19:11:58 [debug] 30743#30743: *162 SSL_read: 55
2016/11/15 19:11:58 [debug] 30743#30743: *162 SSL_read: -1
2016/11/15 19:11:58 [debug] 30743#30743: *162 SSL_get_error: 2
2016/11/15 19:11:58 [debug] 30743#30743: *162 process http2 frame type:1 f:24 l:46 sid:435
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 HEADERS frame sid:435 on 0 excl:0 weight:183
2016/11/15 19:11:58 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E61530:1024 @16
2016/11/15 19:11:58 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E120F0:4096 @16
2016/11/15 19:11:58 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E63480:4096 @16
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 get indexed header name: 3
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 get indexed header name: 69
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 get indexed header name: 7
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 hpack encoded string length: 4
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 hpack encoded string length: 13
2016/11/15 19:11:58 [debug] 30743#30743: *162 http uri: "/appname/v2/heartbeat"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http args: ""
2016/11/15 19:11:58 [debug] 30743#30743: *162 http exten: ""
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 get indexed header: 28
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 hpack encoded string length: 4
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 add header to hpack table: "content-length: 26778"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 hpack table account: 51 free:126
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 http header: "content-length: 26778"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 get indexed header name: 68
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 http header: "accept: application/json, text/plain, */*"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 get indexed header name: 80
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 http header: "origin: https://app3.mydomain.local"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 get indexed header name: 96
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 http header: "appname-csrf-token: YYY
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 get indexed header name: 64
2016/11/15 19:11:58 [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:58 [debug] 30743#30743: *162 http2 get indexed header name: 79
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 http header: "content-type: application/json;charset=UTF-8"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 get indexed header name: 77
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 http header: "accept-encoding: gzip, deflate, br"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 get indexed header name: 93
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 http header: "accept-language: en-US,en;q=0.8"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 get indexed header name: 92
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 get indexed header name: 91
2016/11/15 19:11:58 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E16F00:1024 @16
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 get indexed header name: 90
2016/11/15 19:11:58 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DC4930:1024 @16
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 get indexed header name: 89
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 get indexed header name: 95
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 http request line: "POST /appname/v2/heartbeat HTTP/2.0"
2016/11/15 19:11:58 [debug] 30743#30743: *162 generic phase: 0
2016/11/15 19:11:58 [debug] 30743#30743: *162 rewrite phase: 1
2016/11/15 19:11:58 [debug] 30743#30743: *162 test location: "^/widgets/$"
2016/11/15 19:11:58 [debug] 30743#30743: *162 test location: "/"
2016/11/15 19:11:58 [debug] 30743#30743: *162 test location: "docs/"
2016/11/15 19:11:58 [debug] 30743#30743: *162 test location: "appname/socket"
2016/11/15 19:11:58 [debug] 30743#30743: *162 test location: ~ "^/(index.html)?$"
2016/11/15 19:11:58 [debug] 30743#30743: *162 test location: ~ "^/login/?$"
2016/11/15 19:11:58 [debug] 30743#30743: *162 test location: ~ "^/(appname)"
2016/11/15 19:11:58 [debug] 30743#30743: *162 test location: ~ "/components/(.*)"
2016/11/15 19:11:58 [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:58 [debug] 30743#30743: *162 using configuration "/"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http cl:26778 max:1073741824
2016/11/15 19:11:58 [debug] 30743#30743: *162 rewrite phase: 3
2016/11/15 19:11:58 [debug] 30743#30743: *162 post rewrite phase: 4
2016/11/15 19:11:58 [debug] 30743#30743: *162 generic phase: 5
2016/11/15 19:11:58 [debug] 30743#30743: *162 generic phase: 6
2016/11/15 19:11:58 [debug] 30743#30743: *162 generic phase: 7
2016/11/15 19:11:58 [debug] 30743#30743: *162 access phase: 8
2016/11/15 19:11:58 [debug] 30743#30743: *162 access phase: 9
2016/11/15 19:11:58 [debug] 30743#30743: *162 access phase: 10
2016/11/15 19:11:58 [debug] 30743#30743: *162 auth request handler
2016/11/15 19:11:58 [debug] 30743#30743: *162 posix_memalign: 00000F0D34EB6570:4096 @16
2016/11/15 19:11:58 [debug] 30743#30743: *162 http subrequest "/authorize?"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http posted request: "/authorize?"
2016/11/15 19:11:58 [debug] 30743#30743: *162 rewrite phase: 1
2016/11/15 19:11:58 [debug] 30743#30743: *162 test location: "^/widgets/$"
2016/11/15 19:11:58 [debug] 30743#30743: *162 test location: "/"
2016/11/15 19:11:58 [debug] 30743#30743: *162 test location: "docs/"
2016/11/15 19:11:58 [debug] 30743#30743: *162 test location: "dashboard"
2016/11/15 19:11:58 [debug] 30743#30743: *162 test location: "authorize"
2016/11/15 19:11:58 [debug] 30743#30743: *162 using configuration "=/authorize"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http cl:26778 max:1073741824
2016/11/15 19:11:58 [debug] 30743#30743: *162 rewrite phase: 3
2016/11/15 19:11:58 [debug] 30743#30743: *162 post rewrite phase: 4
2016/11/15 19:11:58 [debug] 30743#30743: *162 generic phase: 5
2016/11/15 19:11:58 [debug] 30743#30743: *162 generic phase: 6
2016/11/15 19:11:58 [debug] 30743#30743: *162 generic phase: 7
2016/11/15 19:11:58 [debug] 30743#30743: *162 http init upstream, client timer: 0
2016/11/15 19:11:58 [debug] 30743#30743: *162 posix_memalign: 00000F0D34EB7580:4096 @16
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: "X-Real-IP: "
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script var: "192.168.123.11"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: "X-Forwarded-For: "
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script var: "192.168.123.11"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: "Host: "
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script var: "app3.mydomain.local"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: "X-NginX-Proxy: true
"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: "X-Client-S-DN: "
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script var: "XXX"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: "X-Client-Serial: "
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script var: "XXXX"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: "x-appname-uri: "
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script var: "/appname/v2/heartbeat"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: "x-appname-method: "
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script var: "POST"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: "Connection: close
"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: ""
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: ""
2016/11/15 19:11:58 [debug] 30743#30743: *162 http proxy header: "accept: application/json, text/plain, */*"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http proxy header: "origin: https://app3.mydomain.local"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http proxy header: "appname-csrf-token: YYY
2016/11/15 19:11:58 [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:58 [debug] 30743#30743: *162 http proxy header: "content-type: application/json;charset=UTF-8"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http proxy header: "accept-encoding: gzip, deflate, br"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http proxy header: "accept-language: en-US,en;q=0.8"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http proxy header: "cookie: XXX"
2016/11/15 19:11:58 [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:58 [debug] 30743#30743: *162 http cleanup add: 00000F0D34E64460
2016/11/15 19:11:58 [debug] 30743#30743: *162 get rr peer, try: 1
2016/11/15 19:11:58 [debug] 30743#30743: *162 stream socket 7
2016/11/15 19:11:58 [debug] 30743#30743: *162 epoll add connection: fd:7 ev:80002005
2016/11/15 19:11:58 [debug] 30743#30743: *162 connect to 127.0.0.1:8008, fd:7 #577
2016/11/15 19:11:58 [debug] 30743#30743: *162 http upstream connect: -2
2016/11/15 19:11:58 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBBA30:128 @16
2016/11/15 19:11:58 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237178556
2016/11/15 19:11:58 [debug] 30743#30743: *162 http finalize request: -4, "/authorize?" a:1, c:3
2016/11/15 19:11:58 [debug] 30743#30743: *162 http request count:3 blk:0
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AC047 end:00006EFC4F5AC047
2016/11/15 19:11:58 [debug] 30743#30743: *162 event timer del: 3: 1479237290608
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 write handler
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 read handler
2016/11/15 19:11:58 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:11:58 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:11:58 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:11:58 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:11:58 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:11:58 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:11:58 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:11:58 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:11:58 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:11:58 [debug] 30743#30743: *162 SSL_read: 1119
2016/11/15 19:11:58 [debug] 30743#30743: *162 SSL_read: -1
2016/11/15 19:11:58 [debug] 30743#30743: *162 SSL_get_error: 2
2016/11/15 19:11:58 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:435
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:11:58 [debug] 30743#30743: *162 malloc: 00000F0D34D89720:65536
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5ACB3D end:00006EFC4F5B2904
2016/11/15 19:11:58 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:435
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AD66A end:00006EFC4F5B2904
2016/11/15 19:11:58 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:435
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AE197 end:00006EFC4F5B2904
2016/11/15 19:11:58 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:435
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AECC4 end:00006EFC4F5B2904
2016/11/15 19:11:58 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:435
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AF7F1 end:00006EFC4F5B2904
2016/11/15 19:11:58 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:435
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5B031E end:00006EFC4F5B2904
2016/11/15 19:11:58 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:435
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5B0E4B end:00006EFC4F5B2904
2016/11/15 19:11:58 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:435
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5B1978 end:00006EFC4F5B2904
2016/11/15 19:11:58 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:435
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5B24A5 end:00006EFC4F5B2904
2016/11/15 19:11:58 [debug] 30743#30743: *162 process http2 frame type:0 f:1 l:1110 sid:435
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5B2904 end:00006EFC4F5B2904
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 write handler
2016/11/15 19:11:58 [debug] 30743#30743: *162 http upstream request: "/authorize?"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http upstream send request handler
2016/11/15 19:11:58 [debug] 30743#30743: *162 http upstream send request
2016/11/15 19:11:58 [debug] 30743#30743: *162 http upstream send request body
2016/11/15 19:11:58 [debug] 30743#30743: *162 chain writer buf fl:1 s:2711
2016/11/15 19:11:58 [debug] 30743#30743: *162 chain writer in: 00000F0D34EB7550
2016/11/15 19:11:58 [debug] 30743#30743: *162 writev: 2711 of 2711
2016/11/15 19:11:58 [debug] 30743#30743: *162 chain writer out: 0000000000000000
2016/11/15 19:11:58 [debug] 30743#30743: *162 event timer del: 7: 1479237178556
2016/11/15 19:11:58 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237178559
2016/11/15 19:11:58 [debug] 30743#30743: *162 http upstream request: "/authorize?"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http upstream process header
2016/11/15 19:11:58 [debug] 30743#30743: *162 malloc: 00000F0D34DBC950:4096
2016/11/15 19:11:58 [debug] 30743#30743: *162 recv: fd:7 172 of 4096
2016/11/15 19:11:58 [debug] 30743#30743: *162 http proxy status 200 "200 OK"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http proxy header: "X-Powered-By: Express"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http proxy header: "x-appname-origin: appname3"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http proxy header: "content-type: application/json"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http proxy header: "content-length: 0"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http proxy header: "Date: Tue, 15 Nov 2016 19:11:58 GMT"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http proxy header: "Connection: close"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http proxy header done
2016/11/15 19:11:58 [debug] 30743#30743: *162 lua capture header filter, uri "/authorize"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 header filter
2016/11/15 19:11:58 [debug] 30743#30743: *162 finalize http upstream request: 0
2016/11/15 19:11:58 [debug] 30743#30743: *162 finalize http proxy request
2016/11/15 19:11:58 [debug] 30743#30743: *162 free rr peer 1 0
2016/11/15 19:11:58 [debug] 30743#30743: *162 close http upstream connection: 7
2016/11/15 19:11:58 [debug] 30743#30743: *162 free: 00000F0D34DBBA30, unused: 48
2016/11/15 19:11:58 [debug] 30743#30743: *162 event timer del: 7: 1479237178559
2016/11/15 19:11:58 [debug] 30743#30743: *162 reusable connection: 0
2016/11/15 19:11:58 [debug] 30743#30743: *162 http finalize request: 0, "/authorize?" a:1, c:2
2016/11/15 19:11:58 [debug] 30743#30743: *162 auth request done s:200
2016/11/15 19:11:58 [debug] 30743#30743: *162 http wake parent request: "/appname/v2/heartbeat?"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http posted request: "/appname/v2/heartbeat?"
2016/11/15 19:11:58 [debug] 30743#30743: *162 access phase: 10
2016/11/15 19:11:58 [debug] 30743#30743: *162 auth request handler
2016/11/15 19:11:58 [debug] 30743#30743: *162 auth request set variables
2016/11/15 19:11:58 [debug] 30743#30743: *162 access phase: 11
2016/11/15 19:11:58 [debug] 30743#30743: *162 lua access handler, uri:"/appname/v2/heartbeat" c:1
2016/11/15 19:11:58 [debug] 30743#30743: *162 post access phase: 12
2016/11/15 19:11:58 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBD960:4096 @16
2016/11/15 19:11:58 [debug] 30743#30743: *162 http body new buf t:1 f:0 00000F0D34D89720, pos 00000F0D34D89720, size: 26778 file: 0, size: 0
2016/11/15 19:11:58 [debug] 30743#30743: *162 http init upstream, client timer: 0
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: "X-Real-IP: "
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script var: "192.168.123.11"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: "X-Forwarded-For: "
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script var: "192.168.123.11"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: "Host: "
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script var: "app3.mydomain.local"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: "X-NginX-Proxy: true
"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: "X-Client-S-DN: "
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script var: "XXX"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: "X-Client-Serial: "
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script var: "XXXX"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: "Connection: close
"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: "Content-Length: "
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script var: "26778"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: ""
2016/11/15 19:11:58 [debug] 30743#30743: *162 http script copy: ""
2016/11/15 19:11:58 [debug] 30743#30743: *162 http proxy header: "accept: application/json, text/plain, */*"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http proxy header: "origin: https://app3.mydomain.local"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http proxy header: "appname-csrf-token: YYY
2016/11/15 19:11:58 [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:58 [debug] 30743#30743: *162 http proxy header: "content-type: application/json;charset=UTF-8"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http proxy header: "accept-encoding: gzip, deflate, br"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http proxy header: "accept-language: en-US,en;q=0.8"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http proxy header: "cookie: XXX"
2016/11/15 19:11:58 [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: 26778
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:58 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBE970:4096 @16
2016/11/15 19:11:58 [debug] 30743#30743: *162 http cleanup add: 00000F0D34DBE938
2016/11/15 19:11:58 [debug] 30743#30743: *162 get rr peer, try: 1
2016/11/15 19:11:58 [debug] 30743#30743: *162 stream socket 7
2016/11/15 19:11:58 [debug] 30743#30743: *162 epoll add connection: fd:7 ev:80002005
2016/11/15 19:11:58 [debug] 30743#30743: *162 connect to 182.168.128.69:8080, fd:7 #578
2016/11/15 19:11:58 [debug] 30743#30743: *162 http upstream connect: -2
2016/11/15 19:11:58 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBBA30:128 @16
2016/11/15 19:11:58 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237178619
2016/11/15 19:11:58 [debug] 30743#30743: *162 free: 00000F0D34D89720
2016/11/15 19:11:58 [debug] 30743#30743: *162 http finalize request: -4, "/appname/v2/heartbeat?" a:1, c:2
2016/11/15 19:11:58 [debug] 30743#30743: *162 http request count:2 blk:0
2016/11/15 19:11:58 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http upstream send request handler
2016/11/15 19:11:58 [debug] 30743#30743: *162 http upstream send request
2016/11/15 19:11:58 [debug] 30743#30743: *162 http upstream send request body
2016/11/15 19:11:58 [debug] 30743#30743: *162 chain writer buf fl:0 s:2690
2016/11/15 19:11:58 [debug] 30743#30743: *162 chain writer buf fl:1 s:26778
2016/11/15 19:11:58 [debug] 30743#30743: *162 chain writer in: 00000F0D34DBEA00
2016/11/15 19:11:58 [debug] 30743#30743: *162 writev: 28960 of 29468
2016/11/15 19:11:58 [debug] 30743#30743: *162 chain writer out: 00000F0D34DBEA10
2016/11/15 19:11:58 [debug] 30743#30743: *162 event timer: 7, old: 1479237178619, new: 1479237178619
2016/11/15 19:11:58 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http upstream send request handler
2016/11/15 19:11:58 [debug] 30743#30743: *162 http upstream send request
2016/11/15 19:11:58 [debug] 30743#30743: *162 http upstream send request body
2016/11/15 19:11:58 [debug] 30743#30743: *162 chain writer in: 00000F0D34DBEA10
2016/11/15 19:11:58 [debug] 30743#30743: *162 writev: 508 of 508
2016/11/15 19:11:58 [debug] 30743#30743: *162 chain writer out: 0000000000000000
2016/11/15 19:11:58 [debug] 30743#30743: *162 event timer del: 7: 1479237178619
2016/11/15 19:11:58 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237178620
2016/11/15 19:11:58 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http upstream process header
2016/11/15 19:11:58 [debug] 30743#30743: *162 malloc: 00000F0D34D69D00:4096
2016/11/15 19:11:58 [debug] 30743#30743: *162 recv: fd:7 1056 of 4096
2016/11/15 19:11:58 [debug] 30743#30743: *162 http proxy status 400 "400 Bad Request"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http proxy header: "Server: nginx"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http proxy header: "Date: Tue, 15 Nov 2016 19:11:59 GMT"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http proxy header: "Content-Type: text/html; charset=utf-8"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http proxy header: "Content-Length: 840"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http proxy header: "Connection: close"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http proxy header: "X-Powered-By: Express"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http proxy header: "X-Content-Type-Options: nosniff"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http proxy header done
2016/11/15 19:11:58 [debug] 30743#30743: *162 lua capture header filter, uri "/appname/v2/heartbeat"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 header filter
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 output header: ":status: 400"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 output header: "server: nginx"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 output header: "date: Tue, 15 Nov 2016 19:11:58 GMT"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 output header: "content-type: text/html; charset=utf-8"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 output header: "content-length: 840"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 output header: "x-powered-by: Express"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 output header: "x-content-type-options: nosniff"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2:435 create HEADERS frame 00000F0D34DBEDA8: len:98
2016/11/15 19:11:58 [debug] 30743#30743: *162 http cleanup add: 00000F0D34DBEE90
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 frame out: 00000F0D34DBEDA8 sid:435 bl:1 len:98
2016/11/15 19:11:58 [debug] 30743#30743: *162 malloc: 00000F0D34D83A10:16384
2016/11/15 19:11:58 [debug] 30743#30743: *162 SSL buf copy: 9
2016/11/15 19:11:58 [debug] 30743#30743: *162 SSL buf copy: 98
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2:435 HEADERS frame 00000F0D34DBEDA8 was sent
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 frame sent: 00000F0D34DBEDA8 sid:435 bl:1 len:98
2016/11/15 19:11:58 [debug] 30743#30743: *162 http cacheable: 0
2016/11/15 19:11:58 [debug] 30743#30743: *162 http proxy filter init s:400 h:0 c:0 l:840
2016/11/15 19:11:58 [debug] 30743#30743: *162 http upstream process upstream
2016/11/15 19:11:58 [debug] 30743#30743: *162 pipe read upstream: 1
2016/11/15 19:11:58 [debug] 30743#30743: *162 pipe preread: 840
2016/11/15 19:11:58 [debug] 30743#30743: *162 readv: 1, last:3040
2016/11/15 19:11:58 [debug] 30743#30743: *162 pipe recv chain: 0
2016/11/15 19:11:58 [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:58 [debug] 30743#30743: *162 pipe length: 840
2016/11/15 19:11:58 [debug] 30743#30743: *162 input buf #0
2016/11/15 19:11:58 [debug] 30743#30743: *162 pipe write downstream: 1
2016/11/15 19:11:58 [debug] 30743#30743: *162 pipe write downstream flush in
2016/11/15 19:11:58 [debug] 30743#30743: *162 http output filter "/appname/v2/heartbeat?"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http copy filter: "/appname/v2/heartbeat?"
2016/11/15 19:11:58 [debug] 30743#30743: *162 lua capture body filter, uri "/appname/v2/heartbeat"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http postpone filter "/appname/v2/heartbeat?" 00000F0D34DBEA00
2016/11/15 19:11:58 [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:58 [debug] 30743#30743: *162 http write filter: l:0 f:0 s:840
2016/11/15 19:11:58 [debug] 30743#30743: *162 http copy filter: 0 "/appname/v2/heartbeat?"
2016/11/15 19:11:58 [debug] 30743#30743: *162 pipe write downstream done
2016/11/15 19:11:58 [debug] 30743#30743: *162 event timer: 7, old: 1479237178620, new: 1479237178649
2016/11/15 19:11:58 [debug] 30743#30743: *162 http upstream exit: 0000000000000000
2016/11/15 19:11:58 [debug] 30743#30743: *162 finalize http upstream request: 0
2016/11/15 19:11:58 [debug] 30743#30743: *162 finalize http proxy request
2016/11/15 19:11:58 [debug] 30743#30743: *162 free rr peer 1 0
2016/11/15 19:11:58 [debug] 30743#30743: *162 close http upstream connection: 7
2016/11/15 19:11:58 [debug] 30743#30743: *162 free: 00000F0D34DBBA30, unused: 48
2016/11/15 19:11:58 [debug] 30743#30743: *162 event timer del: 7: 1479237178620
2016/11/15 19:11:58 [debug] 30743#30743: *162 reusable connection: 0
2016/11/15 19:11:58 [debug] 30743#30743: *162 http upstream temp fd: -1
2016/11/15 19:11:58 [debug] 30743#30743: *162 http output filter "/appname/v2/heartbeat?"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http copy filter: "/appname/v2/heartbeat?"
2016/11/15 19:11:58 [debug] 30743#30743: *162 lua capture body filter, uri "/appname/v2/heartbeat"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http postpone filter "/appname/v2/heartbeat?" 00007A9E70E05A50
2016/11/15 19:11:58 [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:58 [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:58 [debug] 30743#30743: *162 http write filter: l:1 f:0 s:840
2016/11/15 19:11:58 [debug] 30743#30743: *162 http write filter limit 0
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2:435 create DATA frame 00000F0D34DBEDA8: len:840 flags:1
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 frame out: 00000F0D34DBEDA8 sid:435 bl:0 len:840
2016/11/15 19:11:58 [debug] 30743#30743: *162 SSL buf copy: 9
2016/11/15 19:11:58 [debug] 30743#30743: *162 SSL buf copy: 840
2016/11/15 19:11:58 [debug] 30743#30743: *162 SSL to write: 956
2016/11/15 19:11:58 [debug] 30743#30743: *162 SSL_write: 956
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2:435 DATA frame 00000F0D34DBEDA8 was sent
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 frame sent: 00000F0D34DBEDA8 sid:435 bl:0 len:840
2016/11/15 19:11:58 [debug] 30743#30743: *162 http write filter 0000000000000000
2016/11/15 19:11:58 [debug] 30743#30743: *162 http copy filter: 0 "/appname/v2/heartbeat?"
2016/11/15 19:11:58 [debug] 30743#30743: *162 http finalize request: 0, "/appname/v2/heartbeat?" a:1, c:1
2016/11/15 19:11:58 [debug] 30743#30743: *162 http request count:1 blk:0
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 close stream 435, queued 0, processing 1
2016/11/15 19:11:58 [debug] 30743#30743: *162 http close request
2016/11/15 19:11:58 [debug] 30743#30743: *162 http log handler
2016/11/15 19:11:58 [debug] 30743#30743: *162 free: 00000F0D34DBC950
2016/11/15 19:11:58 [debug] 30743#30743: *162 free: 00000F0D34D69D00
2016/11/15 19:11:58 [debug] 30743#30743: *162 free: 00000F0D34E120F0, unused: 0
2016/11/15 19:11:58 [debug] 30743#30743: *162 free: 00000F0D34E63480, unused: 2
2016/11/15 19:11:58 [debug] 30743#30743: *162 free: 00000F0D34EB6570, unused: 0
2016/11/15 19:11:58 [debug] 30743#30743: *162 free: 00000F0D34EB7580, unused: 8
2016/11/15 19:11:58 [debug] 30743#30743: *162 free: 00000F0D34DBD960, unused: 0
2016/11/15 19:11:58 [debug] 30743#30743: *162 free: 00000F0D34DBE970, unused: 1926
2016/11/15 19:11:58 [debug] 30743#30743: *162 free: 00000F0D34E61530, unused: 162
2016/11/15 19:11:58 [debug] 30743#30743: *162 free: 00000F0D34E16F00, unused: 156
2016/11/15 19:11:58 [debug] 30743#30743: *162 free: 00000F0D34DC4930, unused: 111
2016/11/15 19:11:58 [debug] 30743#30743: *162 post event 00006EFC4C5081F0
2016/11/15 19:11:58 [debug] 30743#30743: *162 delete posted event 00006EFC4C5081F0
2016/11/15 19:11:58 [debug] 30743#30743: *162 http2 handle connection handler
2016/11/15 19:11:58 [debug] 30743#30743: *162 free: 00000F0D34E03BC0, unused: 3488
2016/11/15 19:11:58 [debug] 30743#30743: *162 free: 00000F0D34D83A10
2016/11/15 19:11:58 [debug] 30743#30743: *162 reusable connection: 1
2016/11/15 19:11:58 [debug] 30743#30743: *162 event timer add: 3: 180000:1479237298649
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 idle handler
2016/11/15 19:12:02 [debug] 30743#30743: *162 reusable connection: 0
2016/11/15 19:12:02 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E120F0:4096 @16
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 read handler
2016/11/15 19:12:02 [debug] 30743#30743: *162 SSL_read: 55
2016/11/15 19:12:02 [debug] 30743#30743: *162 SSL_read: -1
2016/11/15 19:12:02 [debug] 30743#30743: *162 SSL_get_error: 2
2016/11/15 19:12:02 [debug] 30743#30743: *162 process http2 frame type:1 f:24 l:46 sid:437
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 HEADERS frame sid:437 on 0 excl:0 weight:183
2016/11/15 19:12:02 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DC4930:1024 @16
2016/11/15 19:12:02 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E03BC0:4096 @16
2016/11/15 19:12:02 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E63480:4096 @16
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 get indexed header name: 3
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 get indexed header name: 70
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 get indexed header name: 7
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 hpack encoded string length: 4
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 hpack encoded string length: 13
2016/11/15 19:12:02 [debug] 30743#30743: *162 http uri: "/appname/v2/heartbeat"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http args: ""
2016/11/15 19:12:02 [debug] 30743#30743: *162 http exten: ""
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 get indexed header: 28
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 hpack encoded string length: 4
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 add header to hpack table: "content-length: 16805"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 hpack table account: 51 free:75
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 http header: "content-length: 16805"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 get indexed header name: 69
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 http header: "accept: application/json, text/plain, */*"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 get indexed header name: 81
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 http header: "origin: https://app3.mydomain.local"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 get indexed header name: 97
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 http header: "appname-csrf-token: YYY
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 get indexed header name: 65
2016/11/15 19:12:02 [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:12:02 [debug] 30743#30743: *162 http2 get indexed header name: 80
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 http header: "content-type: application/json;charset=UTF-8"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 get indexed header name: 78
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 http header: "accept-encoding: gzip, deflate, br"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 get indexed header name: 94
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 http header: "accept-language: en-US,en;q=0.8"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 get indexed header name: 93
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 get indexed header name: 92
2016/11/15 19:12:02 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E16F00:1024 @16
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 get indexed header name: 91
2016/11/15 19:12:02 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E61530:1024 @16
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 get indexed header name: 90
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 get indexed header name: 96
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 http request line: "POST /appname/v2/heartbeat HTTP/2.0"
2016/11/15 19:12:02 [debug] 30743#30743: *162 generic phase: 0
2016/11/15 19:12:02 [debug] 30743#30743: *162 rewrite phase: 1
2016/11/15 19:12:02 [debug] 30743#30743: *162 test location: "^/widgets/$"
2016/11/15 19:12:02 [debug] 30743#30743: *162 test location: "/"
2016/11/15 19:12:02 [debug] 30743#30743: *162 test location: "docs/"
2016/11/15 19:12:02 [debug] 30743#30743: *162 test location: "appname/socket"
2016/11/15 19:12:02 [debug] 30743#30743: *162 test location: ~ "^/(index.html)?$"
2016/11/15 19:12:02 [debug] 30743#30743: *162 test location: ~ "^/login/?$"
2016/11/15 19:12:02 [debug] 30743#30743: *162 test location: ~ "^/(appname)"
2016/11/15 19:12:02 [debug] 30743#30743: *162 test location: ~ "/components/(.*)"
2016/11/15 19:12:02 [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:12:02 [debug] 30743#30743: *162 using configuration "/"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http cl:16805 max:1073741824
2016/11/15 19:12:02 [debug] 30743#30743: *162 rewrite phase: 3
2016/11/15 19:12:02 [debug] 30743#30743: *162 post rewrite phase: 4
2016/11/15 19:12:02 [debug] 30743#30743: *162 generic phase: 5
2016/11/15 19:12:02 [debug] 30743#30743: *162 generic phase: 6
2016/11/15 19:12:02 [debug] 30743#30743: *162 generic phase: 7
2016/11/15 19:12:02 [debug] 30743#30743: *162 access phase: 8
2016/11/15 19:12:02 [debug] 30743#30743: *162 access phase: 9
2016/11/15 19:12:02 [debug] 30743#30743: *162 access phase: 10
2016/11/15 19:12:02 [debug] 30743#30743: *162 auth request handler
2016/11/15 19:12:02 [debug] 30743#30743: *162 posix_memalign: 00000F0D34EB6570:4096 @16
2016/11/15 19:12:02 [debug] 30743#30743: *162 http subrequest "/authorize?"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http posted request: "/authorize?"
2016/11/15 19:12:02 [debug] 30743#30743: *162 rewrite phase: 1
2016/11/15 19:12:02 [debug] 30743#30743: *162 test location: "^/widgets/$"
2016/11/15 19:12:02 [debug] 30743#30743: *162 test location: "/"
2016/11/15 19:12:02 [debug] 30743#30743: *162 test location: "docs/"
2016/11/15 19:12:02 [debug] 30743#30743: *162 test location: "dashboard"
2016/11/15 19:12:02 [debug] 30743#30743: *162 test location: "authorize"
2016/11/15 19:12:02 [debug] 30743#30743: *162 using configuration "=/authorize"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http cl:16805 max:1073741824
2016/11/15 19:12:02 [debug] 30743#30743: *162 rewrite phase: 3
2016/11/15 19:12:02 [debug] 30743#30743: *162 post rewrite phase: 4
2016/11/15 19:12:02 [debug] 30743#30743: *162 generic phase: 5
2016/11/15 19:12:02 [debug] 30743#30743: *162 generic phase: 6
2016/11/15 19:12:02 [debug] 30743#30743: *162 generic phase: 7
2016/11/15 19:12:02 [debug] 30743#30743: *162 http init upstream, client timer: 0
2016/11/15 19:12:02 [debug] 30743#30743: *162 posix_memalign: 00000F0D34EB7580:4096 @16
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: "X-Real-IP: "
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script var: "192.168.123.11"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: "X-Forwarded-For: "
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script var: "192.168.123.11"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: "Host: "
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script var: "app3.mydomain.local"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: "X-NginX-Proxy: true
"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: "X-Client-S-DN: "
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script var: "XXX"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: "X-Client-Serial: "
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script var: "XXXX"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: "x-appname-uri: "
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script var: "/appname/v2/heartbeat"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: "x-appname-method: "
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script var: "POST"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: "Connection: close
"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: ""
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: ""
2016/11/15 19:12:02 [debug] 30743#30743: *162 http proxy header: "accept: application/json, text/plain, */*"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http proxy header: "origin: https://app3.mydomain.local"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http proxy header: "appname-csrf-token: YYY
2016/11/15 19:12:02 [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:12:02 [debug] 30743#30743: *162 http proxy header: "content-type: application/json;charset=UTF-8"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http proxy header: "accept-encoding: gzip, deflate, br"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http proxy header: "accept-language: en-US,en;q=0.8"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http proxy header: "cookie: XXX"
2016/11/15 19:12:02 [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:12:02 [debug] 30743#30743: *162 http cleanup add: 00000F0D34E64460
2016/11/15 19:12:02 [debug] 30743#30743: *162 get rr peer, try: 1
2016/11/15 19:12:02 [debug] 30743#30743: *162 stream socket 7
2016/11/15 19:12:02 [debug] 30743#30743: *162 epoll add connection: fd:7 ev:80002005
2016/11/15 19:12:02 [debug] 30743#30743: *162 connect to 127.0.0.1:8008, fd:7 #579
2016/11/15 19:12:02 [debug] 30743#30743: *162 http upstream connect: -2
2016/11/15 19:12:02 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBBA30:128 @16
2016/11/15 19:12:02 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237182563
2016/11/15 19:12:02 [debug] 30743#30743: *162 http finalize request: -4, "/authorize?" a:1, c:3
2016/11/15 19:12:02 [debug] 30743#30743: *162 http request count:3 blk:0
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AC047 end:00006EFC4F5AC047
2016/11/15 19:12:02 [debug] 30743#30743: *162 event timer del: 3: 1479237298649
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 write handler
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 read handler
2016/11/15 19:12:02 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:12:02 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:12:02 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:12:02 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:12:02 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:12:02 [debug] 30743#30743: *162 SSL_read: 2554
2016/11/15 19:12:02 [debug] 30743#30743: *162 SSL_read: -1
2016/11/15 19:12:02 [debug] 30743#30743: *162 SSL_get_error: 2
2016/11/15 19:12:02 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:437
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:12:02 [debug] 30743#30743: *162 malloc: 00000F0D34D89720:65536
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5ACB3D end:00006EFC4F5B01EB
2016/11/15 19:12:02 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:437
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AD66A end:00006EFC4F5B01EB
2016/11/15 19:12:02 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:437
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AE197 end:00006EFC4F5B01EB
2016/11/15 19:12:02 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:437
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AECC4 end:00006EFC4F5B01EB
2016/11/15 19:12:02 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:437
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AF7F1 end:00006EFC4F5B01EB
2016/11/15 19:12:02 [debug] 30743#30743: *162 process http2 frame type:0 f:1 l:2545 sid:437
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5B01EB end:00006EFC4F5B01EB
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 write handler
2016/11/15 19:12:02 [debug] 30743#30743: *162 http upstream request: "/authorize?"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http upstream send request handler
2016/11/15 19:12:02 [debug] 30743#30743: *162 http upstream send request
2016/11/15 19:12:02 [debug] 30743#30743: *162 http upstream send request body
2016/11/15 19:12:02 [debug] 30743#30743: *162 chain writer buf fl:1 s:2711
2016/11/15 19:12:02 [debug] 30743#30743: *162 chain writer in: 00000F0D34EB7550
2016/11/15 19:12:02 [debug] 30743#30743: *162 writev: 2711 of 2711
2016/11/15 19:12:02 [debug] 30743#30743: *162 chain writer out: 0000000000000000
2016/11/15 19:12:02 [debug] 30743#30743: *162 event timer del: 7: 1479237182563
2016/11/15 19:12:02 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237182564
2016/11/15 19:12:02 [debug] 30743#30743: *162 http upstream request: "/authorize?"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http upstream process header
2016/11/15 19:12:02 [debug] 30743#30743: *162 malloc: 00000F0D34DBC950:4096
2016/11/15 19:12:02 [debug] 30743#30743: *162 recv: fd:7 172 of 4096
2016/11/15 19:12:02 [debug] 30743#30743: *162 http proxy status 200 "200 OK"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http proxy header: "X-Powered-By: Express"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http proxy header: "x-appname-origin: appname3"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http proxy header: "content-type: application/json"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http proxy header: "content-length: 0"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http proxy header: "Date: Tue, 15 Nov 2016 19:12:02 GMT"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http proxy header: "Connection: close"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http proxy header done
2016/11/15 19:12:02 [debug] 30743#30743: *162 lua capture header filter, uri "/authorize"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 header filter
2016/11/15 19:12:02 [debug] 30743#30743: *162 finalize http upstream request: 0
2016/11/15 19:12:02 [debug] 30743#30743: *162 finalize http proxy request
2016/11/15 19:12:02 [debug] 30743#30743: *162 free rr peer 1 0
2016/11/15 19:12:02 [debug] 30743#30743: *162 close http upstream connection: 7
2016/11/15 19:12:02 [debug] 30743#30743: *162 free: 00000F0D34DBBA30, unused: 48
2016/11/15 19:12:02 [debug] 30743#30743: *162 event timer del: 7: 1479237182564
2016/11/15 19:12:02 [debug] 30743#30743: *162 reusable connection: 0
2016/11/15 19:12:02 [debug] 30743#30743: *162 http finalize request: 0, "/authorize?" a:1, c:2
2016/11/15 19:12:02 [debug] 30743#30743: *162 auth request done s:200
2016/11/15 19:12:02 [debug] 30743#30743: *162 http wake parent request: "/appname/v2/heartbeat?"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http posted request: "/appname/v2/heartbeat?"
2016/11/15 19:12:02 [debug] 30743#30743: *162 access phase: 10
2016/11/15 19:12:02 [debug] 30743#30743: *162 auth request handler
2016/11/15 19:12:02 [debug] 30743#30743: *162 auth request set variables
2016/11/15 19:12:02 [debug] 30743#30743: *162 access phase: 11
2016/11/15 19:12:02 [debug] 30743#30743: *162 lua access handler, uri:"/appname/v2/heartbeat" c:1
2016/11/15 19:12:02 [debug] 30743#30743: *162 post access phase: 12
2016/11/15 19:12:02 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBD960:4096 @16
2016/11/15 19:12:02 [debug] 30743#30743: *162 http body new buf t:1 f:0 00000F0D34D89720, pos 00000F0D34D89720, size: 16805 file: 0, size: 0
2016/11/15 19:12:02 [debug] 30743#30743: *162 http init upstream, client timer: 0
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: "X-Real-IP: "
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script var: "192.168.123.11"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: "X-Forwarded-For: "
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script var: "192.168.123.11"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: "Host: "
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script var: "app3.mydomain.local"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: "X-NginX-Proxy: true
"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: "X-Client-S-DN: "
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script var: "XXX"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: "X-Client-Serial: "
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script var: "XXXX"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: "Connection: close
"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: "Content-Length: "
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script var: "16805"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: ""
2016/11/15 19:12:02 [debug] 30743#30743: *162 http script copy: ""
2016/11/15 19:12:02 [debug] 30743#30743: *162 http proxy header: "accept: application/json, text/plain, */*"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http proxy header: "origin: https://app3.mydomain.local"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http proxy header: "appname-csrf-token: YYY
2016/11/15 19:12:02 [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:12:02 [debug] 30743#30743: *162 http proxy header: "content-type: application/json;charset=UTF-8"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http proxy header: "accept-encoding: gzip, deflate, br"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http proxy header: "accept-language: en-US,en;q=0.8"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http proxy header: "cookie: XXX"
2016/11/15 19:12:02 [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: 16805
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:12:02 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBE970:4096 @16
2016/11/15 19:12:02 [debug] 30743#30743: *162 http cleanup add: 00000F0D34DBE938
2016/11/15 19:12:02 [debug] 30743#30743: *162 get rr peer, try: 1
2016/11/15 19:12:02 [debug] 30743#30743: *162 stream socket 7
2016/11/15 19:12:02 [debug] 30743#30743: *162 epoll add connection: fd:7 ev:80002005
2016/11/15 19:12:02 [debug] 30743#30743: *162 connect to 182.168.128.69:8080, fd:7 #580
2016/11/15 19:12:02 [debug] 30743#30743: *162 http upstream connect: -2
2016/11/15 19:12:02 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBBA30:128 @16
2016/11/15 19:12:02 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237182594
2016/11/15 19:12:02 [debug] 30743#30743: *162 free: 00000F0D34D89720
2016/11/15 19:12:02 [debug] 30743#30743: *162 http finalize request: -4, "/appname/v2/heartbeat?" a:1, c:2
2016/11/15 19:12:02 [debug] 30743#30743: *162 http request count:2 blk:0
2016/11/15 19:12:02 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http upstream send request handler
2016/11/15 19:12:02 [debug] 30743#30743: *162 http upstream send request
2016/11/15 19:12:02 [debug] 30743#30743: *162 http upstream send request body
2016/11/15 19:12:02 [debug] 30743#30743: *162 chain writer buf fl:0 s:2690
2016/11/15 19:12:02 [debug] 30743#30743: *162 chain writer buf fl:1 s:16805
2016/11/15 19:12:02 [debug] 30743#30743: *162 chain writer in: 00000F0D34DBEA00
2016/11/15 19:12:02 [debug] 30743#30743: *162 writev: 19495 of 19495
2016/11/15 19:12:02 [debug] 30743#30743: *162 chain writer out: 0000000000000000
2016/11/15 19:12:02 [debug] 30743#30743: *162 event timer del: 7: 1479237182594
2016/11/15 19:12:02 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237182594
2016/11/15 19:12:02 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http upstream process header
2016/11/15 19:12:02 [debug] 30743#30743: *162 malloc: 00000F0D34D69D00:4096
2016/11/15 19:12:02 [debug] 30743#30743: *162 recv: fd:7 1056 of 4096
2016/11/15 19:12:02 [debug] 30743#30743: *162 http proxy status 400 "400 Bad Request"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http proxy header: "Server: nginx"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http proxy header: "Date: Tue, 15 Nov 2016 19:12:02 GMT"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http proxy header: "Content-Type: text/html; charset=utf-8"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http proxy header: "Content-Length: 840"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http proxy header: "Connection: close"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http proxy header: "X-Powered-By: Express"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http proxy header: "X-Content-Type-Options: nosniff"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http proxy header done
2016/11/15 19:12:02 [debug] 30743#30743: *162 lua capture header filter, uri "/appname/v2/heartbeat"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 header filter
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 output header: ":status: 400"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 output header: "server: nginx"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 output header: "date: Tue, 15 Nov 2016 19:12:02 GMT"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 output header: "content-type: text/html; charset=utf-8"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 output header: "content-length: 840"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 output header: "x-powered-by: Express"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 output header: "x-content-type-options: nosniff"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2:437 create HEADERS frame 00000F0D34DBEDA8: len:98
2016/11/15 19:12:02 [debug] 30743#30743: *162 http cleanup add: 00000F0D34DBEE90
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 frame out: 00000F0D34DBEDA8 sid:437 bl:1 len:98
2016/11/15 19:12:02 [debug] 30743#30743: *162 malloc: 00000F0D34D83A10:16384
2016/11/15 19:12:02 [debug] 30743#30743: *162 SSL buf copy: 9
2016/11/15 19:12:02 [debug] 30743#30743: *162 SSL buf copy: 98
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2:437 HEADERS frame 00000F0D34DBEDA8 was sent
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 frame sent: 00000F0D34DBEDA8 sid:437 bl:1 len:98
2016/11/15 19:12:02 [debug] 30743#30743: *162 http cacheable: 0
2016/11/15 19:12:02 [debug] 30743#30743: *162 http proxy filter init s:400 h:0 c:0 l:840
2016/11/15 19:12:02 [debug] 30743#30743: *162 http upstream process upstream
2016/11/15 19:12:02 [debug] 30743#30743: *162 pipe read upstream: 1
2016/11/15 19:12:02 [debug] 30743#30743: *162 pipe preread: 840
2016/11/15 19:12:02 [debug] 30743#30743: *162 readv: 1, last:3040
2016/11/15 19:12:02 [debug] 30743#30743: *162 pipe recv chain: 0
2016/11/15 19:12:02 [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:12:02 [debug] 30743#30743: *162 pipe length: 840
2016/11/15 19:12:02 [debug] 30743#30743: *162 input buf #0
2016/11/15 19:12:02 [debug] 30743#30743: *162 pipe write downstream: 1
2016/11/15 19:12:02 [debug] 30743#30743: *162 pipe write downstream flush in
2016/11/15 19:12:02 [debug] 30743#30743: *162 http output filter "/appname/v2/heartbeat?"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http copy filter: "/appname/v2/heartbeat?"
2016/11/15 19:12:02 [debug] 30743#30743: *162 lua capture body filter, uri "/appname/v2/heartbeat"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http postpone filter "/appname/v2/heartbeat?" 00000F0D34DBEA00
2016/11/15 19:12:02 [debug] 30743#30743: *162 write new buf t:1 f:0 00000F0D34D69D00, pos 00000F0D34D69DD8, size: 840 file: 0, size: 0
2016/11/15 19:12:02 [debug] 30743#30743: *162 http write filter: l:0 f:0 s:840
2016/11/15 19:12:02 [debug] 30743#30743: *162 http copy filter: 0 "/appname/v2/heartbeat?"
2016/11/15 19:12:02 [debug] 30743#30743: *162 pipe write downstream done
2016/11/15 19:12:02 [debug] 30743#30743: *162 event timer: 7, old: 1479237182594, new: 1479237182602
2016/11/15 19:12:02 [debug] 30743#30743: *162 http upstream exit: 0000000000000000
2016/11/15 19:12:02 [debug] 30743#30743: *162 finalize http upstream request: 0
2016/11/15 19:12:02 [debug] 30743#30743: *162 finalize http proxy request
2016/11/15 19:12:02 [debug] 30743#30743: *162 free rr peer 1 0
2016/11/15 19:12:02 [debug] 30743#30743: *162 close http upstream connection: 7
2016/11/15 19:12:02 [debug] 30743#30743: *162 free: 00000F0D34DBBA30, unused: 48
2016/11/15 19:12:02 [debug] 30743#30743: *162 event timer del: 7: 1479237182594
2016/11/15 19:12:02 [debug] 30743#30743: *162 reusable connection: 0
2016/11/15 19:12:02 [debug] 30743#30743: *162 http upstream temp fd: -1
2016/11/15 19:12:02 [debug] 30743#30743: *162 http output filter "/appname/v2/heartbeat?"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http copy filter: "/appname/v2/heartbeat?"
2016/11/15 19:12:02 [debug] 30743#30743: *162 lua capture body filter, uri "/appname/v2/heartbeat"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http postpone filter "/appname/v2/heartbeat?" 00007A9E70E05A50
2016/11/15 19:12:02 [debug] 30743#30743: *162 write old buf t:1 f:0 00000F0D34D69D00, pos 00000F0D34D69DD8, size: 840 file: 0, size: 0
2016/11/15 19:12:02 [debug] 30743#30743: *162 write new buf t:0 f:0 0000000000000000, pos 0000000000000000, size: 0 file: 0, size: 0
2016/11/15 19:12:02 [debug] 30743#30743: *162 http write filter: l:1 f:0 s:840
2016/11/15 19:12:02 [debug] 30743#30743: *162 http write filter limit 0
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2:437 create DATA frame 00000F0D34DBEDA8: len:840 flags:1
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 frame out: 00000F0D34DBEDA8 sid:437 bl:0 len:840
2016/11/15 19:12:02 [debug] 30743#30743: *162 SSL buf copy: 9
2016/11/15 19:12:02 [debug] 30743#30743: *162 SSL buf copy: 840
2016/11/15 19:12:02 [debug] 30743#30743: *162 SSL to write: 956
2016/11/15 19:12:02 [debug] 30743#30743: *162 SSL_write: 956
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2:437 DATA frame 00000F0D34DBEDA8 was sent
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 frame sent: 00000F0D34DBEDA8 sid:437 bl:0 len:840
2016/11/15 19:12:02 [debug] 30743#30743: *162 http write filter 0000000000000000
2016/11/15 19:12:02 [debug] 30743#30743: *162 http copy filter: 0 "/appname/v2/heartbeat?"
2016/11/15 19:12:02 [debug] 30743#30743: *162 http finalize request: 0, "/appname/v2/heartbeat?" a:1, c:1
2016/11/15 19:12:02 [debug] 30743#30743: *162 http request count:1 blk:0
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 close stream 437, queued 0, processing 1
2016/11/15 19:12:02 [debug] 30743#30743: *162 http close request
2016/11/15 19:12:02 [debug] 30743#30743: *162 http log handler
2016/11/15 19:12:02 [debug] 30743#30743: *162 free: 00000F0D34DBC950
2016/11/15 19:12:02 [debug] 30743#30743: *162 free: 00000F0D34D69D00
2016/11/15 19:12:02 [debug] 30743#30743: *162 free: 00000F0D34E03BC0, unused: 0
2016/11/15 19:12:02 [debug] 30743#30743: *162 free: 00000F0D34E63480, unused: 2
2016/11/15 19:12:02 [debug] 30743#30743: *162 free: 00000F0D34EB6570, unused: 0
2016/11/15 19:12:02 [debug] 30743#30743: *162 free: 00000F0D34EB7580, unused: 8
2016/11/15 19:12:02 [debug] 30743#30743: *162 free: 00000F0D34DBD960, unused: 0
2016/11/15 19:12:02 [debug] 30743#30743: *162 free: 00000F0D34DBE970, unused: 1926
2016/11/15 19:12:02 [debug] 30743#30743: *162 free: 00000F0D34DC4930, unused: 162
2016/11/15 19:12:02 [debug] 30743#30743: *162 free: 00000F0D34E16F00, unused: 156
2016/11/15 19:12:02 [debug] 30743#30743: *162 free: 00000F0D34E61530, unused: 111
2016/11/15 19:12:02 [debug] 30743#30743: *162 post event 00006EFC4C5081F0
2016/11/15 19:12:02 [debug] 30743#30743: *162 delete posted event 00006EFC4C5081F0
2016/11/15 19:12:02 [debug] 30743#30743: *162 http2 handle connection handler
2016/11/15 19:12:02 [debug] 30743#30743: *162 free: 00000F0D34E120F0, unused: 3488
2016/11/15 19:12:02 [debug] 30743#30743: *162 free: 00000F0D34D83A10
2016/11/15 19:12:02 [debug] 30743#30743: *162 reusable connection: 1
2016/11/15 19:12:02 [debug] 30743#30743: *162 event timer add: 3: 180000:1479237302602
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 idle handler
2016/11/15 19:12:08 [debug] 30743#30743: *162 reusable connection: 0
2016/11/15 19:12:08 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E03BC0:4096 @16
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 read handler
2016/11/15 19:12:08 [debug] 30743#30743: *162 SSL_read: 55
2016/11/15 19:12:08 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:12:08 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:12:08 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:12:08 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:12:08 [debug] 30743#30743: *162 SSL_read: -1
2016/11/15 19:12:08 [debug] 30743#30743: *162 SSL_get_error: 2
2016/11/15 19:12:08 [debug] 30743#30743: *162 process http2 frame type:1 f:24 l:46 sid:439
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 HEADERS frame sid:439 on 0 excl:0 weight:183
2016/11/15 19:12:08 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E61530:1024 @16
2016/11/15 19:12:08 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E120F0:4096 @16
2016/11/15 19:12:08 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E63480:4096 @16
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 get indexed header name: 3
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 get indexed header name: 71
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 get indexed header name: 7
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 hpack encoded string length: 4
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 hpack encoded string length: 13
2016/11/15 19:12:08 [debug] 30743#30743: *162 http uri: "/appname/v2/heartbeat"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http args: ""
2016/11/15 19:12:08 [debug] 30743#30743: *162 http exten: ""
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 get indexed header: 28
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 hpack encoded string length: 4
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 add header to hpack table: "content-length: 26988"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 hpack table account: 51 free:24
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 http header: "content-length: 26988"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 get indexed header name: 70
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 http header: "accept: application/json, text/plain, */*"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 get indexed header name: 82
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 http header: "origin: https://app3.mydomain.local"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 get indexed header name: 98
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 http header: "appname-csrf-token: YYY
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 get indexed header name: 66
2016/11/15 19:12:08 [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:12:08 [debug] 30743#30743: *162 http2 get indexed header name: 81
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 http header: "content-type: application/json;charset=UTF-8"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 get indexed header name: 79
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 http header: "accept-encoding: gzip, deflate, br"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 get indexed header name: 95
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 http header: "accept-language: en-US,en;q=0.8"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 get indexed header name: 94
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 get indexed header name: 93
2016/11/15 19:12:08 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E16F00:1024 @16
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 get indexed header name: 92
2016/11/15 19:12:08 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DC4930:1024 @16
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 get indexed header name: 91
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 get indexed header name: 97
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 http request line: "POST /appname/v2/heartbeat HTTP/2.0"
2016/11/15 19:12:08 [debug] 30743#30743: *162 generic phase: 0
2016/11/15 19:12:08 [debug] 30743#30743: *162 rewrite phase: 1
2016/11/15 19:12:08 [debug] 30743#30743: *162 test location: "^/widgets/$"
2016/11/15 19:12:08 [debug] 30743#30743: *162 test location: "/"
2016/11/15 19:12:08 [debug] 30743#30743: *162 test location: "docs/"
2016/11/15 19:12:08 [debug] 30743#30743: *162 test location: "appname/socket"
2016/11/15 19:12:08 [debug] 30743#30743: *162 test location: ~ "^/(index.html)?$"
2016/11/15 19:12:08 [debug] 30743#30743: *162 test location: ~ "^/login/?$"
2016/11/15 19:12:08 [debug] 30743#30743: *162 test location: ~ "^/(appname)"
2016/11/15 19:12:08 [debug] 30743#30743: *162 test location: ~ "/components/(.*)"
2016/11/15 19:12:08 [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:12:08 [debug] 30743#30743: *162 using configuration "/"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http cl:26988 max:1073741824
2016/11/15 19:12:08 [debug] 30743#30743: *162 rewrite phase: 3
2016/11/15 19:12:08 [debug] 30743#30743: *162 post rewrite phase: 4
2016/11/15 19:12:08 [debug] 30743#30743: *162 generic phase: 5
2016/11/15 19:12:08 [debug] 30743#30743: *162 generic phase: 6
2016/11/15 19:12:08 [debug] 30743#30743: *162 generic phase: 7
2016/11/15 19:12:08 [debug] 30743#30743: *162 access phase: 8
2016/11/15 19:12:08 [debug] 30743#30743: *162 access phase: 9
2016/11/15 19:12:08 [debug] 30743#30743: *162 access phase: 10
2016/11/15 19:12:08 [debug] 30743#30743: *162 auth request handler
2016/11/15 19:12:08 [debug] 30743#30743: *162 posix_memalign: 00000F0D34EB6570:4096 @16
2016/11/15 19:12:08 [debug] 30743#30743: *162 http subrequest "/authorize?"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http posted request: "/authorize?"
2016/11/15 19:12:08 [debug] 30743#30743: *162 rewrite phase: 1
2016/11/15 19:12:08 [debug] 30743#30743: *162 test location: "^/widgets/$"
2016/11/15 19:12:08 [debug] 30743#30743: *162 test location: "/"
2016/11/15 19:12:08 [debug] 30743#30743: *162 test location: "docs/"
2016/11/15 19:12:08 [debug] 30743#30743: *162 test location: "dashboard"
2016/11/15 19:12:08 [debug] 30743#30743: *162 test location: "authorize"
2016/11/15 19:12:08 [debug] 30743#30743: *162 using configuration "=/authorize"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http cl:26988 max:1073741824
2016/11/15 19:12:08 [debug] 30743#30743: *162 rewrite phase: 3
2016/11/15 19:12:08 [debug] 30743#30743: *162 post rewrite phase: 4
2016/11/15 19:12:08 [debug] 30743#30743: *162 generic phase: 5
2016/11/15 19:12:08 [debug] 30743#30743: *162 generic phase: 6
2016/11/15 19:12:08 [debug] 30743#30743: *162 generic phase: 7
2016/11/15 19:12:08 [debug] 30743#30743: *162 http init upstream, client timer: 0
2016/11/15 19:12:08 [debug] 30743#30743: *162 posix_memalign: 00000F0D34EB7580:4096 @16
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: "X-Real-IP: "
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script var: "192.168.123.11"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: "X-Forwarded-For: "
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script var: "192.168.123.11"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: "Host: "
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script var: "app3.mydomain.local"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: "X-NginX-Proxy: true
"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: "X-Client-S-DN: "
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script var: "XXX"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: "X-Client-Serial: "
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script var: "XXXX"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: "x-appname-uri: "
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script var: "/appname/v2/heartbeat"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: "x-appname-method: "
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script var: "POST"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: "Connection: close
"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: ""
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: ""
2016/11/15 19:12:08 [debug] 30743#30743: *162 http proxy header: "accept: application/json, text/plain, */*"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http proxy header: "origin: https://app3.mydomain.local"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http proxy header: "appname-csrf-token: YYY
2016/11/15 19:12:08 [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:12:08 [debug] 30743#30743: *162 http proxy header: "content-type: application/json;charset=UTF-8"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http proxy header: "accept-encoding: gzip, deflate, br"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http proxy header: "accept-language: en-US,en;q=0.8"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http proxy header: "cookie: XXX"
2016/11/15 19:12:08 [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:12:08 [debug] 30743#30743: *162 http cleanup add: 00000F0D34E64460
2016/11/15 19:12:08 [debug] 30743#30743: *162 get rr peer, try: 1
2016/11/15 19:12:08 [debug] 30743#30743: *162 stream socket 7
2016/11/15 19:12:08 [debug] 30743#30743: *162 epoll add connection: fd:7 ev:80002005
2016/11/15 19:12:08 [debug] 30743#30743: *162 connect to 127.0.0.1:8008, fd:7 #581
2016/11/15 19:12:08 [debug] 30743#30743: *162 http upstream connect: -2
2016/11/15 19:12:08 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBBA30:128 @16
2016/11/15 19:12:08 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237188658
2016/11/15 19:12:08 [debug] 30743#30743: *162 http finalize request: -4, "/authorize?" a:1, c:3
2016/11/15 19:12:08 [debug] 30743#30743: *162 http request count:3 blk:0
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AC047 end:00006EFC4F5AECFB
2016/11/15 19:12:08 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:439
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:12:08 [debug] 30743#30743: *162 malloc: 00000F0D34D89720:65536
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5ACB74 end:00006EFC4F5AECFB
2016/11/15 19:12:08 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:439
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AD6A1 end:00006EFC4F5AECFB
2016/11/15 19:12:08 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:439
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AE1CE end:00006EFC4F5AECFB
2016/11/15 19:12:08 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:439
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AECFB end:00006EFC4F5AECFB
2016/11/15 19:12:08 [debug] 30743#30743: *162 event timer del: 3: 1479237302602
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 write handler
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 read handler
2016/11/15 19:12:08 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:12:08 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:12:08 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:12:08 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:12:08 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:12:08 [debug] 30743#30743: *162 SSL_read: 1329
2016/11/15 19:12:08 [debug] 30743#30743: *162 SSL_read: -1
2016/11/15 19:12:08 [debug] 30743#30743: *162 SSL_get_error: 2
2016/11/15 19:12:08 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:439
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5ACB3D end:00006EFC4F5AFD22
2016/11/15 19:12:08 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:439
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AD66A end:00006EFC4F5AFD22
2016/11/15 19:12:08 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:439
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AE197 end:00006EFC4F5AFD22
2016/11/15 19:12:08 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:439
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AECC4 end:00006EFC4F5AFD22
2016/11/15 19:12:08 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:439
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AF7F1 end:00006EFC4F5AFD22
2016/11/15 19:12:08 [debug] 30743#30743: *162 process http2 frame type:0 f:1 l:1320 sid:439
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AFD22 end:00006EFC4F5AFD22
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 write handler
2016/11/15 19:12:08 [debug] 30743#30743: *162 http upstream request: "/authorize?"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http upstream send request handler
2016/11/15 19:12:08 [debug] 30743#30743: *162 http upstream send request
2016/11/15 19:12:08 [debug] 30743#30743: *162 http upstream send request body
2016/11/15 19:12:08 [debug] 30743#30743: *162 chain writer buf fl:1 s:2711
2016/11/15 19:12:08 [debug] 30743#30743: *162 chain writer in: 00000F0D34EB7550
2016/11/15 19:12:08 [debug] 30743#30743: *162 writev: 2711 of 2711
2016/11/15 19:12:08 [debug] 30743#30743: *162 chain writer out: 0000000000000000
2016/11/15 19:12:08 [debug] 30743#30743: *162 event timer del: 7: 1479237188658
2016/11/15 19:12:08 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237188659
2016/11/15 19:12:08 [debug] 30743#30743: *162 http upstream request: "/authorize?"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http upstream process header
2016/11/15 19:12:08 [debug] 30743#30743: *162 malloc: 00000F0D34DBC950:4096
2016/11/15 19:12:08 [debug] 30743#30743: *162 recv: fd:7 172 of 4096
2016/11/15 19:12:08 [debug] 30743#30743: *162 http proxy status 200 "200 OK"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http proxy header: "X-Powered-By: Express"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http proxy header: "x-appname-origin: appname3"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http proxy header: "content-type: application/json"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http proxy header: "content-length: 0"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http proxy header: "Date: Tue, 15 Nov 2016 19:12:08 GMT"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http proxy header: "Connection: close"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http proxy header done
2016/11/15 19:12:08 [debug] 30743#30743: *162 lua capture header filter, uri "/authorize"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 header filter
2016/11/15 19:12:08 [debug] 30743#30743: *162 finalize http upstream request: 0
2016/11/15 19:12:08 [debug] 30743#30743: *162 finalize http proxy request
2016/11/15 19:12:08 [debug] 30743#30743: *162 free rr peer 1 0
2016/11/15 19:12:08 [debug] 30743#30743: *162 close http upstream connection: 7
2016/11/15 19:12:08 [debug] 30743#30743: *162 free: 00000F0D34DBBA30, unused: 48
2016/11/15 19:12:08 [debug] 30743#30743: *162 event timer del: 7: 1479237188659
2016/11/15 19:12:08 [debug] 30743#30743: *162 reusable connection: 0
2016/11/15 19:12:08 [debug] 30743#30743: *162 http finalize request: 0, "/authorize?" a:1, c:2
2016/11/15 19:12:08 [debug] 30743#30743: *162 auth request done s:200
2016/11/15 19:12:08 [debug] 30743#30743: *162 http wake parent request: "/appname/v2/heartbeat?"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http posted request: "/appname/v2/heartbeat?"
2016/11/15 19:12:08 [debug] 30743#30743: *162 access phase: 10
2016/11/15 19:12:08 [debug] 30743#30743: *162 auth request handler
2016/11/15 19:12:08 [debug] 30743#30743: *162 auth request set variables
2016/11/15 19:12:08 [debug] 30743#30743: *162 access phase: 11
2016/11/15 19:12:08 [debug] 30743#30743: *162 lua access handler, uri:"/appname/v2/heartbeat" c:1
2016/11/15 19:12:08 [debug] 30743#30743: *162 post access phase: 12
2016/11/15 19:12:08 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBD960:4096 @16
2016/11/15 19:12:08 [debug] 30743#30743: *162 http body new buf t:1 f:0 00000F0D34D89720, pos 00000F0D34D89720, size: 26988 file: 0, size: 0
2016/11/15 19:12:08 [debug] 30743#30743: *162 http init upstream, client timer: 0
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: "X-Real-IP: "
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script var: "192.168.123.11"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: "X-Forwarded-For: "
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script var: "192.168.123.11"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: "Host: "
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script var: "app3.mydomain.local"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: "X-NginX-Proxy: true
"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: "X-Client-S-DN: "
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script var: "XXX"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: "X-Client-Serial: "
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script var: "XXXX"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: "Connection: close
"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: "Content-Length: "
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script var: "26988"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: ""
2016/11/15 19:12:08 [debug] 30743#30743: *162 http script copy: ""
2016/11/15 19:12:08 [debug] 30743#30743: *162 http proxy header: "accept: application/json, text/plain, */*"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http proxy header: "origin: https://app3.mydomain.local"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http proxy header: "appname-csrf-token: YYY
2016/11/15 19:12:08 [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:12:08 [debug] 30743#30743: *162 http proxy header: "content-type: application/json;charset=UTF-8"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http proxy header: "accept-encoding: gzip, deflate, br"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http proxy header: "accept-language: en-US,en;q=0.8"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http proxy header: "cookie: XXX"
2016/11/15 19:12:08 [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: 26988
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:12:08 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBE970:4096 @16
2016/11/15 19:12:08 [debug] 30743#30743: *162 http cleanup add: 00000F0D34DBE938
2016/11/15 19:12:08 [debug] 30743#30743: *162 get rr peer, try: 1
2016/11/15 19:12:08 [debug] 30743#30743: *162 stream socket 7
2016/11/15 19:12:08 [debug] 30743#30743: *162 epoll add connection: fd:7 ev:80002005
2016/11/15 19:12:08 [debug] 30743#30743: *162 connect to 182.168.128.69:8080, fd:7 #582
2016/11/15 19:12:08 [debug] 30743#30743: *162 http upstream connect: -2
2016/11/15 19:12:08 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBBA30:128 @16
2016/11/15 19:12:08 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237188684
2016/11/15 19:12:08 [debug] 30743#30743: *162 free: 00000F0D34D89720
2016/11/15 19:12:08 [debug] 30743#30743: *162 http finalize request: -4, "/appname/v2/heartbeat?" a:1, c:2
2016/11/15 19:12:08 [debug] 30743#30743: *162 http request count:2 blk:0
2016/11/15 19:12:08 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http upstream send request handler
2016/11/15 19:12:08 [debug] 30743#30743: *162 http upstream send request
2016/11/15 19:12:08 [debug] 30743#30743: *162 http upstream send request body
2016/11/15 19:12:08 [debug] 30743#30743: *162 chain writer buf fl:0 s:2690
2016/11/15 19:12:08 [debug] 30743#30743: *162 chain writer buf fl:1 s:26988
2016/11/15 19:12:08 [debug] 30743#30743: *162 chain writer in: 00000F0D34DBEA00
2016/11/15 19:12:08 [debug] 30743#30743: *162 writev: 28960 of 29678
2016/11/15 19:12:08 [debug] 30743#30743: *162 chain writer out: 00000F0D34DBEA10
2016/11/15 19:12:08 [debug] 30743#30743: *162 event timer: 7, old: 1479237188684, new: 1479237188684
2016/11/15 19:12:08 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http upstream send request handler
2016/11/15 19:12:08 [debug] 30743#30743: *162 http upstream send request
2016/11/15 19:12:08 [debug] 30743#30743: *162 http upstream send request body
2016/11/15 19:12:08 [debug] 30743#30743: *162 chain writer in: 00000F0D34DBEA10
2016/11/15 19:12:08 [debug] 30743#30743: *162 writev: 718 of 718
2016/11/15 19:12:08 [debug] 30743#30743: *162 chain writer out: 0000000000000000
2016/11/15 19:12:08 [debug] 30743#30743: *162 event timer del: 7: 1479237188684
2016/11/15 19:12:08 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237188685
2016/11/15 19:12:08 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http upstream process header
2016/11/15 19:12:08 [debug] 30743#30743: *162 malloc: 00000F0D34D69D00:4096
2016/11/15 19:12:08 [debug] 30743#30743: *162 recv: fd:7 1056 of 4096
2016/11/15 19:12:08 [debug] 30743#30743: *162 http proxy status 400 "400 Bad Request"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http proxy header: "Server: nginx"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http proxy header: "Date: Tue, 15 Nov 2016 19:12:08 GMT"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http proxy header: "Content-Type: text/html; charset=utf-8"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http proxy header: "Content-Length: 840"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http proxy header: "Connection: close"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http proxy header: "X-Powered-By: Express"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http proxy header: "X-Content-Type-Options: nosniff"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http proxy header done
2016/11/15 19:12:08 [debug] 30743#30743: *162 lua capture header filter, uri "/appname/v2/heartbeat"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 header filter
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 output header: ":status: 400"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 output header: "server: nginx"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 output header: "date: Tue, 15 Nov 2016 19:12:08 GMT"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 output header: "content-type: text/html; charset=utf-8"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 output header: "content-length: 840"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 output header: "x-powered-by: Express"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 output header: "x-content-type-options: nosniff"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2:439 create HEADERS frame 00000F0D34DBEDA8: len:98
2016/11/15 19:12:08 [debug] 30743#30743: *162 http cleanup add: 00000F0D34DBEE90
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 frame out: 00000F0D34DBEDA8 sid:439 bl:1 len:98
2016/11/15 19:12:08 [debug] 30743#30743: *162 malloc: 00000F0D34D83A10:16384
2016/11/15 19:12:08 [debug] 30743#30743: *162 SSL buf copy: 9
2016/11/15 19:12:08 [debug] 30743#30743: *162 SSL buf copy: 98
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2:439 HEADERS frame 00000F0D34DBEDA8 was sent
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 frame sent: 00000F0D34DBEDA8 sid:439 bl:1 len:98
2016/11/15 19:12:08 [debug] 30743#30743: *162 http cacheable: 0
2016/11/15 19:12:08 [debug] 30743#30743: *162 http proxy filter init s:400 h:0 c:0 l:840
2016/11/15 19:12:08 [debug] 30743#30743: *162 http upstream process upstream
2016/11/15 19:12:08 [debug] 30743#30743: *162 pipe read upstream: 1
2016/11/15 19:12:08 [debug] 30743#30743: *162 pipe preread: 840
2016/11/15 19:12:08 [debug] 30743#30743: *162 readv: 1, last:3040
2016/11/15 19:12:08 [debug] 30743#30743: *162 pipe recv chain: 0
2016/11/15 19:12:08 [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:12:08 [debug] 30743#30743: *162 pipe length: 840
2016/11/15 19:12:08 [debug] 30743#30743: *162 input buf #0
2016/11/15 19:12:08 [debug] 30743#30743: *162 pipe write downstream: 1
2016/11/15 19:12:08 [debug] 30743#30743: *162 pipe write downstream flush in
2016/11/15 19:12:08 [debug] 30743#30743: *162 http output filter "/appname/v2/heartbeat?"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http copy filter: "/appname/v2/heartbeat?"
2016/11/15 19:12:08 [debug] 30743#30743: *162 lua capture body filter, uri "/appname/v2/heartbeat"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http postpone filter "/appname/v2/heartbeat?" 00000F0D34DBEA00
2016/11/15 19:12:08 [debug] 30743#30743: *162 write new buf t:1 f:0 00000F0D34D69D00, pos 00000F0D34D69DD8, size: 840 file: 0, size: 0
2016/11/15 19:12:08 [debug] 30743#30743: *162 http write filter: l:0 f:0 s:840
2016/11/15 19:12:08 [debug] 30743#30743: *162 http copy filter: 0 "/appname/v2/heartbeat?"
2016/11/15 19:12:08 [debug] 30743#30743: *162 pipe write downstream done
2016/11/15 19:12:08 [debug] 30743#30743: *162 event timer: 7, old: 1479237188685, new: 1479237188696
2016/11/15 19:12:08 [debug] 30743#30743: *162 http upstream exit: 0000000000000000
2016/11/15 19:12:08 [debug] 30743#30743: *162 finalize http upstream request: 0
2016/11/15 19:12:08 [debug] 30743#30743: *162 finalize http proxy request
2016/11/15 19:12:08 [debug] 30743#30743: *162 free rr peer 1 0
2016/11/15 19:12:08 [debug] 30743#30743: *162 close http upstream connection: 7
2016/11/15 19:12:08 [debug] 30743#30743: *162 free: 00000F0D34DBBA30, unused: 48
2016/11/15 19:12:08 [debug] 30743#30743: *162 event timer del: 7: 1479237188685
2016/11/15 19:12:08 [debug] 30743#30743: *162 reusable connection: 0
2016/11/15 19:12:08 [debug] 30743#30743: *162 http upstream temp fd: -1
2016/11/15 19:12:08 [debug] 30743#30743: *162 http output filter "/appname/v2/heartbeat?"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http copy filter: "/appname/v2/heartbeat?"
2016/11/15 19:12:08 [debug] 30743#30743: *162 lua capture body filter, uri "/appname/v2/heartbeat"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http postpone filter "/appname/v2/heartbeat?" 00007A9E70E05A50
2016/11/15 19:12:08 [debug] 30743#30743: *162 write old buf t:1 f:0 00000F0D34D69D00, pos 00000F0D34D69DD8, size: 840 file: 0, size: 0
2016/11/15 19:12:08 [debug] 30743#30743: *162 write new buf t:0 f:0 0000000000000000, pos 0000000000000000, size: 0 file: 0, size: 0
2016/11/15 19:12:08 [debug] 30743#30743: *162 http write filter: l:1 f:0 s:840
2016/11/15 19:12:08 [debug] 30743#30743: *162 http write filter limit 0
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2:439 create DATA frame 00000F0D34DBEDA8: len:840 flags:1
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 frame out: 00000F0D34DBEDA8 sid:439 bl:0 len:840
2016/11/15 19:12:08 [debug] 30743#30743: *162 SSL buf copy: 9
2016/11/15 19:12:08 [debug] 30743#30743: *162 SSL buf copy: 840
2016/11/15 19:12:08 [debug] 30743#30743: *162 SSL to write: 956
2016/11/15 19:12:08 [debug] 30743#30743: *162 SSL_write: 956
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2:439 DATA frame 00000F0D34DBEDA8 was sent
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 frame sent: 00000F0D34DBEDA8 sid:439 bl:0 len:840
2016/11/15 19:12:08 [debug] 30743#30743: *162 http write filter 0000000000000000
2016/11/15 19:12:08 [debug] 30743#30743: *162 http copy filter: 0 "/appname/v2/heartbeat?"
2016/11/15 19:12:08 [debug] 30743#30743: *162 http finalize request: 0, "/appname/v2/heartbeat?" a:1, c:1
2016/11/15 19:12:08 [debug] 30743#30743: *162 http request count:1 blk:0
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 close stream 439, queued 0, processing 1
2016/11/15 19:12:08 [debug] 30743#30743: *162 http close request
2016/11/15 19:12:08 [debug] 30743#30743: *162 http log handler
2016/11/15 19:12:08 [debug] 30743#30743: *162 free: 00000F0D34DBC950
2016/11/15 19:12:08 [debug] 30743#30743: *162 free: 00000F0D34D69D00
2016/11/15 19:12:08 [debug] 30743#30743: *162 free: 00000F0D34E120F0, unused: 0
2016/11/15 19:12:08 [debug] 30743#30743: *162 free: 00000F0D34E63480, unused: 2
2016/11/15 19:12:08 [debug] 30743#30743: *162 free: 00000F0D34EB6570, unused: 0
2016/11/15 19:12:08 [debug] 30743#30743: *162 free: 00000F0D34EB7580, unused: 8
2016/11/15 19:12:08 [debug] 30743#30743: *162 free: 00000F0D34DBD960, unused: 0
2016/11/15 19:12:08 [debug] 30743#30743: *162 free: 00000F0D34DBE970, unused: 1926
2016/11/15 19:12:08 [debug] 30743#30743: *162 free: 00000F0D34E61530, unused: 162
2016/11/15 19:12:08 [debug] 30743#30743: *162 free: 00000F0D34E16F00, unused: 156
2016/11/15 19:12:08 [debug] 30743#30743: *162 free: 00000F0D34DC4930, unused: 111
2016/11/15 19:12:08 [debug] 30743#30743: *162 post event 00006EFC4C5081F0
2016/11/15 19:12:08 [debug] 30743#30743: *162 delete posted event 00006EFC4C5081F0
2016/11/15 19:12:08 [debug] 30743#30743: *162 http2 handle connection handler
2016/11/15 19:12:08 [debug] 30743#30743: *162 free: 00000F0D34E03BC0, unused: 3488
2016/11/15 19:12:08 [debug] 30743#30743: *162 free: 00000F0D34D83A10
2016/11/15 19:12:08 [debug] 30743#30743: *162 reusable connection: 1
2016/11/15 19:12:08 [debug] 30743#30743: *162 event timer add: 3: 180000:1479237308696
2016/11/15 19:12:13 [debug] 30741#30741: *251 post event 00006EFC4C5081F0
2016/11/15 19:12:13 [debug] 30741#30741: *251 post event 00006EFC4C2071F0
2016/11/15 19:12:13 [debug] 30741#30741: *251 delete posted event 00006EFC4C5081F0
2016/11/15 19:12:13 [debug] 30741#30741: *251 http run request: "/appname/socket/?EIO=3&transport=websocket&sid=UJyFqU73bEe42MVkAAAB"
2016/11/15 19:12:13 [debug] 30741#30741: *251 http upstream process upgraded, fu:0
2016/11/15 19:12:13 [debug] 30741#30741: *251 SSL_read: 9
2016/11/15 19:12:13 [debug] 30741#30741: *251 SSL_read: -1
2016/11/15 19:12:13 [debug] 30741#30741: *251 SSL_get_error: 2
2016/11/15 19:12:13 [debug] 30741#30741: *251 send: fd:14 9 of 9
2016/11/15 19:12:13 [debug] 30741#30741: *251 event timer del: 14: 1479237168070
2016/11/15 19:12:13 [debug] 30741#30741: *251 event timer add: 14: 60000:1479237193075
2016/11/15 19:12:13 [debug] 30741#30741: *251 delete posted event 00006EFC4C2071F0
2016/11/15 19:12:13 [debug] 30741#30741: *251 http run request: "/appname/socket/?EIO=3&transport=websocket&sid=UJyFqU73bEe42MVkAAAB"
2016/11/15 19:12:13 [debug] 30741#30741: *251 http upstream process upgraded, fu:1
2016/11/15 19:12:13 [debug] 30741#30741: *251 event timer: 14, old: 1479237193075, new: 1479237193075
2016/11/15 19:12:13 [debug] 30741#30741: *251 post event 00006EFC4C508250
2016/11/15 19:12:13 [debug] 30741#30741: *251 post event 00006EFC4C207250
2016/11/15 19:12:13 [debug] 30741#30741: *251 delete posted event 00006EFC4C508250
2016/11/15 19:12:13 [debug] 30741#30741: *251 http upstream request: "/appname/socket/?EIO=3&transport=websocket&sid=UJyFqU73bEe42MVkAAAB"
2016/11/15 19:12:13 [debug] 30741#30741: *251 http upstream process upgraded, fu:1
2016/11/15 19:12:13 [debug] 30741#30741: *251 recv: fd:14 3 of 4096
2016/11/15 19:12:13 [debug] 30741#30741: *251 SSL to write: 3
2016/11/15 19:12:13 [debug] 30741#30741: *251 SSL_write: 3
2016/11/15 19:12:13 [debug] 30741#30741: *251 recv: fd:14 -1 of 4096
2016/11/15 19:12:13 [debug] 30741#30741: *251 recv() not ready (11: Resource temporarily unavailable)
2016/11/15 19:12:13 [debug] 30741#30741: *251 event timer: 14, old: 1479237193075, new: 1479237193080
2016/11/15 19:12:13 [debug] 30741#30741: *251 delete posted event 00006EFC4C207250
2016/11/15 19:12:13 [debug] 30741#30741: *251 http upstream request: "/appname/socket/?EIO=3&transport=websocket&sid=UJyFqU73bEe42MVkAAAB"
2016/11/15 19:12:13 [debug] 30741#30741: *251 http upstream process upgraded, fu:0
2016/11/15 19:12:13 [debug] 30741#30741: *251 event timer: 14, old: 1479237193075, new: 1479237193080
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 idle handler
2016/11/15 19:12:14 [debug] 30743#30743: *162 reusable connection: 0
2016/11/15 19:12:14 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E120F0:4096 @16
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 read handler
2016/11/15 19:12:14 [debug] 30743#30743: *162 SSL_read: 314
2016/11/15 19:12:14 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:12:14 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:12:14 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:12:14 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:12:14 [debug] 30743#30743: *162 SSL_read: -1
2016/11/15 19:12:14 [debug] 30743#30743: *162 SSL_get_error: 2
2016/11/15 19:12:14 [debug] 30743#30743: *162 process http2 frame type:1 f:24 l:305 sid:441
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 HEADERS frame sid:441 on 0 excl:0 weight:183
2016/11/15 19:12:14 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DC4930:1024 @16
2016/11/15 19:12:14 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E03BC0:4096 @16
2016/11/15 19:12:14 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E63480:4096 @16
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 get indexed header name: 3
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 get indexed header name: 72
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 get indexed header name: 7
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 hpack encoded string length: 4
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 hpack encoded string length: 13
2016/11/15 19:12:14 [debug] 30743#30743: *162 http uri: "/appname/v2/heartbeat"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http args: ""
2016/11/15 19:12:14 [debug] 30743#30743: *162 http exten: ""
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 get indexed header: 28
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 hpack encoded string length: 4
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 add header to hpack table: "content-length: 17015"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 hpack table account: 51 free:22
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 http header: "content-length: 17015"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 get indexed header name: 71
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 http header: "accept: application/json, text/plain, */*"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 get indexed header name: 83
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 http header: "origin: https://app3.mydomain.local"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 hpack encoded string length: 11
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 hpack encoded string length: 116
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 add header to hpack table: "appname-csrf-token: YYY
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 hpack table account: 191 free:162
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 http header: "appname-csrf-token: YYY
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 get indexed header name: 68
2016/11/15 19:12:14 [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:12:14 [debug] 30743#30743: *162 http2 get indexed header name: 83
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 http header: "content-type: application/json;charset=UTF-8"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 get indexed header name: 81
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 http header: "accept-encoding: gzip, deflate, br"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 get indexed header name: 97
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 http header: "accept-language: en-US,en;q=0.8"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 get indexed header name: 96
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 get indexed header name: 95
2016/11/15 19:12:14 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E16F00:1024 @16
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 get indexed header name: 94
2016/11/15 19:12:14 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E61530:1024 @16
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 get indexed header name: 93
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 get indexed header: 32
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 hpack encoded string length: 128
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 add header to hpack table: "cookie: XXX"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 hpack table account: 198 free:169
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 http request line: "POST /appname/v2/heartbeat HTTP/2.0"
2016/11/15 19:12:14 [debug] 30743#30743: *162 generic phase: 0
2016/11/15 19:12:14 [debug] 30743#30743: *162 rewrite phase: 1
2016/11/15 19:12:14 [debug] 30743#30743: *162 test location: "^/widgets/$"
2016/11/15 19:12:14 [debug] 30743#30743: *162 test location: "/"
2016/11/15 19:12:14 [debug] 30743#30743: *162 test location: "docs/"
2016/11/15 19:12:14 [debug] 30743#30743: *162 test location: "appname/socket"
2016/11/15 19:12:14 [debug] 30743#30743: *162 test location: ~ "^/(index.html)?$"
2016/11/15 19:12:14 [debug] 30743#30743: *162 test location: ~ "^/login/?$"
2016/11/15 19:12:14 [debug] 30743#30743: *162 test location: ~ "^/(appname)"
2016/11/15 19:12:14 [debug] 30743#30743: *162 test location: ~ "/components/(.*)"
2016/11/15 19:12:14 [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:12:14 [debug] 30743#30743: *162 using configuration "/"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http cl:17015 max:1073741824
2016/11/15 19:12:14 [debug] 30743#30743: *162 rewrite phase: 3
2016/11/15 19:12:14 [debug] 30743#30743: *162 post rewrite phase: 4
2016/11/15 19:12:14 [debug] 30743#30743: *162 generic phase: 5
2016/11/15 19:12:14 [debug] 30743#30743: *162 generic phase: 6
2016/11/15 19:12:14 [debug] 30743#30743: *162 generic phase: 7
2016/11/15 19:12:14 [debug] 30743#30743: *162 access phase: 8
2016/11/15 19:12:14 [debug] 30743#30743: *162 access phase: 9
2016/11/15 19:12:14 [debug] 30743#30743: *162 access phase: 10
2016/11/15 19:12:14 [debug] 30743#30743: *162 auth request handler
2016/11/15 19:12:14 [debug] 30743#30743: *162 posix_memalign: 00000F0D34EB6570:4096 @16
2016/11/15 19:12:14 [debug] 30743#30743: *162 http subrequest "/authorize?"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http posted request: "/authorize?"
2016/11/15 19:12:14 [debug] 30743#30743: *162 rewrite phase: 1
2016/11/15 19:12:14 [debug] 30743#30743: *162 test location: "^/widgets/$"
2016/11/15 19:12:14 [debug] 30743#30743: *162 test location: "/"
2016/11/15 19:12:14 [debug] 30743#30743: *162 test location: "docs/"
2016/11/15 19:12:14 [debug] 30743#30743: *162 test location: "dashboard"
2016/11/15 19:12:14 [debug] 30743#30743: *162 test location: "authorize"
2016/11/15 19:12:14 [debug] 30743#30743: *162 using configuration "=/authorize"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http cl:17015 max:1073741824
2016/11/15 19:12:14 [debug] 30743#30743: *162 rewrite phase: 3
2016/11/15 19:12:14 [debug] 30743#30743: *162 post rewrite phase: 4
2016/11/15 19:12:14 [debug] 30743#30743: *162 generic phase: 5
2016/11/15 19:12:14 [debug] 30743#30743: *162 generic phase: 6
2016/11/15 19:12:14 [debug] 30743#30743: *162 generic phase: 7
2016/11/15 19:12:14 [debug] 30743#30743: *162 http init upstream, client timer: 0
2016/11/15 19:12:14 [debug] 30743#30743: *162 posix_memalign: 00000F0D34EB7580:4096 @16
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: "X-Real-IP: "
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script var: "192.168.123.11"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: "X-Forwarded-For: "
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script var: "192.168.123.11"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: "Host: "
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script var: "app3.mydomain.local"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: "X-NginX-Proxy: true
"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: "X-Client-S-DN: "
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script var: "XXX"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: "X-Client-Serial: "
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script var: "XXXX"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: "x-appname-uri: "
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script var: "/appname/v2/heartbeat"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: "x-appname-method: "
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script var: "POST"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: "Connection: close
"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: ""
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: ""
2016/11/15 19:12:14 [debug] 30743#30743: *162 http proxy header: "accept: application/json, text/plain, */*"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http proxy header: "origin: https://app3.mydomain.local"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http proxy header: "appname-csrf-token: YYY
2016/11/15 19:12:14 [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:12:14 [debug] 30743#30743: *162 http proxy header: "content-type: application/json;charset=UTF-8"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http proxy header: "accept-encoding: gzip, deflate, br"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http proxy header: "accept-language: en-US,en;q=0.8"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http proxy header: "cookie: XXX"
2016/11/15 19:12:14 [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:12:14 [debug] 30743#30743: *162 http cleanup add: 00000F0D34E64460
2016/11/15 19:12:14 [debug] 30743#30743: *162 get rr peer, try: 1
2016/11/15 19:12:14 [debug] 30743#30743: *162 stream socket 7
2016/11/15 19:12:14 [debug] 30743#30743: *162 epoll add connection: fd:7 ev:80002005
2016/11/15 19:12:14 [debug] 30743#30743: *162 connect to 127.0.0.1:8008, fd:7 #583
2016/11/15 19:12:14 [debug] 30743#30743: *162 http upstream connect: -2
2016/11/15 19:12:14 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBBA30:128 @16
2016/11/15 19:12:14 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237194568
2016/11/15 19:12:14 [debug] 30743#30743: *162 http finalize request: -4, "/authorize?" a:1, c:3
2016/11/15 19:12:14 [debug] 30743#30743: *162 http request count:3 blk:0
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AC14A end:00006EFC4F5AEDFE
2016/11/15 19:12:14 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:441
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:12:14 [debug] 30743#30743: *162 malloc: 00000F0D34D89720:65536
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5ACC77 end:00006EFC4F5AEDFE
2016/11/15 19:12:14 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:441
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AD7A4 end:00006EFC4F5AEDFE
2016/11/15 19:12:14 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:441
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AE2D1 end:00006EFC4F5AEDFE
2016/11/15 19:12:14 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:441
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AEDFE end:00006EFC4F5AEDFE
2016/11/15 19:12:14 [debug] 30743#30743: *162 event timer del: 3: 1479237308696
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 write handler
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 read handler
2016/11/15 19:12:14 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:12:14 [debug] 30743#30743: *162 SSL_read: 2764
2016/11/15 19:12:14 [debug] 30743#30743: *162 SSL_read: -1
2016/11/15 19:12:14 [debug] 30743#30743: *162 SSL_get_error: 2
2016/11/15 19:12:14 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:441
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5ACB3D end:00006EFC4F5AD609
2016/11/15 19:12:14 [debug] 30743#30743: *162 process http2 frame type:0 f:1 l:2755 sid:441
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 DATA frame
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AD609 end:00006EFC4F5AD609
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 write handler
2016/11/15 19:12:14 [debug] 30743#30743: *162 http upstream request: "/authorize?"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http upstream send request handler
2016/11/15 19:12:14 [debug] 30743#30743: *162 http upstream send request
2016/11/15 19:12:14 [debug] 30743#30743: *162 http upstream send request body
2016/11/15 19:12:14 [debug] 30743#30743: *162 chain writer buf fl:1 s:2711
2016/11/15 19:12:14 [debug] 30743#30743: *162 chain writer in: 00000F0D34EB7550
2016/11/15 19:12:14 [debug] 30743#30743: *162 writev: 2711 of 2711
2016/11/15 19:12:14 [debug] 30743#30743: *162 chain writer out: 0000000000000000
2016/11/15 19:12:14 [debug] 30743#30743: *162 event timer del: 7: 1479237194568
2016/11/15 19:12:14 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237194569
2016/11/15 19:12:14 [debug] 30743#30743: *162 http upstream request: "/authorize?"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http upstream process header
2016/11/15 19:12:14 [debug] 30743#30743: *162 malloc: 00000F0D34DBC950:4096
2016/11/15 19:12:14 [debug] 30743#30743: *162 recv: fd:7 172 of 4096
2016/11/15 19:12:14 [debug] 30743#30743: *162 http proxy status 200 "200 OK"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http proxy header: "X-Powered-By: Express"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http proxy header: "x-appname-origin: appname3"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http proxy header: "content-type: application/json"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http proxy header: "content-length: 0"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http proxy header: "Date: Tue, 15 Nov 2016 19:12:14 GMT"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http proxy header: "Connection: close"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http proxy header done
2016/11/15 19:12:14 [debug] 30743#30743: *162 lua capture header filter, uri "/authorize"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 header filter
2016/11/15 19:12:14 [debug] 30743#30743: *162 finalize http upstream request: 0
2016/11/15 19:12:14 [debug] 30743#30743: *162 finalize http proxy request
2016/11/15 19:12:14 [debug] 30743#30743: *162 free rr peer 1 0
2016/11/15 19:12:14 [debug] 30743#30743: *162 close http upstream connection: 7
2016/11/15 19:12:14 [debug] 30743#30743: *162 free: 00000F0D34DBBA30, unused: 48
2016/11/15 19:12:14 [debug] 30743#30743: *162 event timer del: 7: 1479237194569
2016/11/15 19:12:14 [debug] 30743#30743: *162 reusable connection: 0
2016/11/15 19:12:14 [debug] 30743#30743: *162 http finalize request: 0, "/authorize?" a:1, c:2
2016/11/15 19:12:14 [debug] 30743#30743: *162 auth request done s:200
2016/11/15 19:12:14 [debug] 30743#30743: *162 http wake parent request: "/appname/v2/heartbeat?"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http posted request: "/appname/v2/heartbeat?"
2016/11/15 19:12:14 [debug] 30743#30743: *162 access phase: 10
2016/11/15 19:12:14 [debug] 30743#30743: *162 auth request handler
2016/11/15 19:12:14 [debug] 30743#30743: *162 auth request set variables
2016/11/15 19:12:14 [debug] 30743#30743: *162 access phase: 11
2016/11/15 19:12:14 [debug] 30743#30743: *162 lua access handler, uri:"/appname/v2/heartbeat" c:1
2016/11/15 19:12:14 [debug] 30743#30743: *162 post access phase: 12
2016/11/15 19:12:14 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBD960:4096 @16
2016/11/15 19:12:14 [debug] 30743#30743: *162 http body new buf t:1 f:0 00000F0D34D89720, pos 00000F0D34D89720, size: 17015 file: 0, size: 0
2016/11/15 19:12:14 [debug] 30743#30743: *162 http init upstream, client timer: 0
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: "X-Real-IP: "
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script var: "192.168.123.11"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: "X-Forwarded-For: "
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script var: "192.168.123.11"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: "Host: "
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script var: "app3.mydomain.local"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: "X-NginX-Proxy: true
"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: "X-Client-S-DN: "
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script var: "XXX"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: "X-Client-Serial: "
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script var: "XXXX"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: "Connection: close
"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: "Content-Length: "
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script var: "17015"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: ""
2016/11/15 19:12:14 [debug] 30743#30743: *162 http script copy: ""
2016/11/15 19:12:14 [debug] 30743#30743: *162 http proxy header: "accept: application/json, text/plain, */*"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http proxy header: "origin: https://app3.mydomain.local"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http proxy header: "appname-csrf-token: YYY
2016/11/15 19:12:14 [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:12:14 [debug] 30743#30743: *162 http proxy header: "content-type: application/json;charset=UTF-8"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http proxy header: "accept-encoding: gzip, deflate, br"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http proxy header: "accept-language: en-US,en;q=0.8"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http proxy header: "cookie: XXX"
2016/11/15 19:12:14 [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: 17015
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:12:14 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBE970:4096 @16
2016/11/15 19:12:14 [debug] 30743#30743: *162 http cleanup add: 00000F0D34DBE938
2016/11/15 19:12:14 [debug] 30743#30743: *162 get rr peer, try: 1
2016/11/15 19:12:14 [debug] 30743#30743: *162 stream socket 7
2016/11/15 19:12:14 [debug] 30743#30743: *162 epoll add connection: fd:7 ev:80002005
2016/11/15 19:12:14 [debug] 30743#30743: *162 connect to 182.168.128.69:8080, fd:7 #584
2016/11/15 19:12:14 [debug] 30743#30743: *162 http upstream connect: -2
2016/11/15 19:12:14 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBBA30:128 @16
2016/11/15 19:12:14 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237194591
2016/11/15 19:12:14 [debug] 30743#30743: *162 free: 00000F0D34D89720
2016/11/15 19:12:14 [debug] 30743#30743: *162 http finalize request: -4, "/appname/v2/heartbeat?" a:1, c:2
2016/11/15 19:12:14 [debug] 30743#30743: *162 http request count:2 blk:0
2016/11/15 19:12:14 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http upstream send request handler
2016/11/15 19:12:14 [debug] 30743#30743: *162 http upstream send request
2016/11/15 19:12:14 [debug] 30743#30743: *162 http upstream send request body
2016/11/15 19:12:14 [debug] 30743#30743: *162 chain writer buf fl:0 s:2690
2016/11/15 19:12:14 [debug] 30743#30743: *162 chain writer buf fl:1 s:17015
2016/11/15 19:12:14 [debug] 30743#30743: *162 chain writer in: 00000F0D34DBEA00
2016/11/15 19:12:14 [debug] 30743#30743: *162 writev: 19705 of 19705
2016/11/15 19:12:14 [debug] 30743#30743: *162 chain writer out: 0000000000000000
2016/11/15 19:12:14 [debug] 30743#30743: *162 event timer del: 7: 1479237194591
2016/11/15 19:12:14 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237194592
2016/11/15 19:12:14 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http upstream process header
2016/11/15 19:12:14 [debug] 30743#30743: *162 malloc: 00000F0D34D69D00:4096
2016/11/15 19:12:14 [debug] 30743#30743: *162 recv: fd:7 1056 of 4096
2016/11/15 19:12:14 [debug] 30743#30743: *162 http proxy status 400 "400 Bad Request"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http proxy header: "Server: nginx"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http proxy header: "Date: Tue, 15 Nov 2016 19:12:12 GMT"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http proxy header: "Content-Type: text/html; charset=utf-8"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http proxy header: "Content-Length: 840"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http proxy header: "Connection: close"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http proxy header: "X-Powered-By: Express"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http proxy header: "X-Content-Type-Options: nosniff"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http proxy header done
2016/11/15 19:12:14 [debug] 30743#30743: *162 lua capture header filter, uri "/appname/v2/heartbeat"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 header filter
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 output header: ":status: 400"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 output header: "server: nginx"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 output header: "date: Tue, 15 Nov 2016 19:12:14 GMT"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 output header: "content-type: text/html; charset=utf-8"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 output header: "content-length: 840"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 output header: "x-powered-by: Express"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 output header: "x-content-type-options: nosniff"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2:441 create HEADERS frame 00000F0D34DBEDA8: len:98
2016/11/15 19:12:14 [debug] 30743#30743: *162 http cleanup add: 00000F0D34DBEE90
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 frame out: 00000F0D34DBEDA8 sid:441 bl:1 len:98
2016/11/15 19:12:14 [debug] 30743#30743: *162 malloc: 00000F0D34D83A10:16384
2016/11/15 19:12:14 [debug] 30743#30743: *162 SSL buf copy: 9
2016/11/15 19:12:14 [debug] 30743#30743: *162 SSL buf copy: 98
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2:441 HEADERS frame 00000F0D34DBEDA8 was sent
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 frame sent: 00000F0D34DBEDA8 sid:441 bl:1 len:98
2016/11/15 19:12:14 [debug] 30743#30743: *162 http cacheable: 0
2016/11/15 19:12:14 [debug] 30743#30743: *162 http proxy filter init s:400 h:0 c:0 l:840
2016/11/15 19:12:14 [debug] 30743#30743: *162 http upstream process upstream
2016/11/15 19:12:14 [debug] 30743#30743: *162 pipe read upstream: 1
2016/11/15 19:12:14 [debug] 30743#30743: *162 pipe preread: 840
2016/11/15 19:12:14 [debug] 30743#30743: *162 readv: 1, last:3040
2016/11/15 19:12:14 [debug] 30743#30743: *162 pipe recv chain: 0
2016/11/15 19:12:14 [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:12:14 [debug] 30743#30743: *162 pipe length: 840
2016/11/15 19:12:14 [debug] 30743#30743: *162 input buf #0
2016/11/15 19:12:14 [debug] 30743#30743: *162 pipe write downstream: 1
2016/11/15 19:12:14 [debug] 30743#30743: *162 pipe write downstream flush in
2016/11/15 19:12:14 [debug] 30743#30743: *162 http output filter "/appname/v2/heartbeat?"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http copy filter: "/appname/v2/heartbeat?"
2016/11/15 19:12:14 [debug] 30743#30743: *162 lua capture body filter, uri "/appname/v2/heartbeat"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http postpone filter "/appname/v2/heartbeat?" 00000F0D34DBEA00
2016/11/15 19:12:14 [debug] 30743#30743: *162 write new buf t:1 f:0 00000F0D34D69D00, pos 00000F0D34D69DD8, size: 840 file: 0, size: 0
2016/11/15 19:12:14 [debug] 30743#30743: *162 http write filter: l:0 f:0 s:840
2016/11/15 19:12:14 [debug] 30743#30743: *162 http copy filter: 0 "/appname/v2/heartbeat?"
2016/11/15 19:12:14 [debug] 30743#30743: *162 pipe write downstream done
2016/11/15 19:12:14 [debug] 30743#30743: *162 event timer: 7, old: 1479237194592, new: 1479237194600
2016/11/15 19:12:14 [debug] 30743#30743: *162 http upstream exit: 0000000000000000
2016/11/15 19:12:14 [debug] 30743#30743: *162 finalize http upstream request: 0
2016/11/15 19:12:14 [debug] 30743#30743: *162 finalize http proxy request
2016/11/15 19:12:14 [debug] 30743#30743: *162 free rr peer 1 0
2016/11/15 19:12:14 [debug] 30743#30743: *162 close http upstream connection: 7
2016/11/15 19:12:14 [debug] 30743#30743: *162 free: 00000F0D34DBBA30, unused: 48
2016/11/15 19:12:14 [debug] 30743#30743: *162 event timer del: 7: 1479237194592
2016/11/15 19:12:14 [debug] 30743#30743: *162 reusable connection: 0
2016/11/15 19:12:14 [debug] 30743#30743: *162 http upstream temp fd: -1
2016/11/15 19:12:14 [debug] 30743#30743: *162 http output filter "/appname/v2/heartbeat?"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http copy filter: "/appname/v2/heartbeat?"
2016/11/15 19:12:14 [debug] 30743#30743: *162 lua capture body filter, uri "/appname/v2/heartbeat"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http postpone filter "/appname/v2/heartbeat?" 00007A9E70E05A50
2016/11/15 19:12:14 [debug] 30743#30743: *162 write old buf t:1 f:0 00000F0D34D69D00, pos 00000F0D34D69DD8, size: 840 file: 0, size: 0
2016/11/15 19:12:14 [debug] 30743#30743: *162 write new buf t:0 f:0 0000000000000000, pos 0000000000000000, size: 0 file: 0, size: 0
2016/11/15 19:12:14 [debug] 30743#30743: *162 http write filter: l:1 f:0 s:840
2016/11/15 19:12:14 [debug] 30743#30743: *162 http write filter limit 0
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2:441 create DATA frame 00000F0D34DBEDA8: len:840 flags:1
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 frame out: 00000F0D34DBEDA8 sid:441 bl:0 len:840
2016/11/15 19:12:14 [debug] 30743#30743: *162 SSL buf copy: 9
2016/11/15 19:12:14 [debug] 30743#30743: *162 SSL buf copy: 840
2016/11/15 19:12:14 [debug] 30743#30743: *162 SSL to write: 956
2016/11/15 19:12:14 [debug] 30743#30743: *162 SSL_write: 956
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2:441 DATA frame 00000F0D34DBEDA8 was sent
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 frame sent: 00000F0D34DBEDA8 sid:441 bl:0 len:840
2016/11/15 19:12:14 [debug] 30743#30743: *162 http write filter 0000000000000000
2016/11/15 19:12:14 [debug] 30743#30743: *162 http copy filter: 0 "/appname/v2/heartbeat?"
2016/11/15 19:12:14 [debug] 30743#30743: *162 http finalize request: 0, "/appname/v2/heartbeat?" a:1, c:1
2016/11/15 19:12:14 [debug] 30743#30743: *162 http request count:1 blk:0
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 close stream 441, queued 0, processing 1
2016/11/15 19:12:14 [debug] 30743#30743: *162 http close request
2016/11/15 19:12:14 [debug] 30743#30743: *162 http log handler
2016/11/15 19:12:14 [debug] 30743#30743: *162 free: 00000F0D34DBC950
2016/11/15 19:12:14 [debug] 30743#30743: *162 free: 00000F0D34D69D00
2016/11/15 19:12:14 [debug] 30743#30743: *162 free: 00000F0D34E03BC0, unused: 0
2016/11/15 19:12:14 [debug] 30743#30743: *162 free: 00000F0D34E63480, unused: 2
2016/11/15 19:12:14 [debug] 30743#30743: *162 free: 00000F0D34EB6570, unused: 0
2016/11/15 19:12:14 [debug] 30743#30743: *162 free: 00000F0D34EB7580, unused: 8
2016/11/15 19:12:14 [debug] 30743#30743: *162 free: 00000F0D34DBD960, unused: 0
2016/11/15 19:12:14 [debug] 30743#30743: *162 free: 00000F0D34DBE970, unused: 1926
2016/11/15 19:12:14 [debug] 30743#30743: *162 free: 00000F0D34DC4930, unused: 82
2016/11/15 19:12:14 [debug] 30743#30743: *162 free: 00000F0D34E16F00, unused: 156
2016/11/15 19:12:14 [debug] 30743#30743: *162 free: 00000F0D34E61530, unused: 111
2016/11/15 19:12:14 [debug] 30743#30743: *162 post event 00006EFC4C5081F0
2016/11/15 19:12:14 [debug] 30743#30743: *162 delete posted event 00006EFC4C5081F0
2016/11/15 19:12:14 [debug] 30743#30743: *162 http2 handle connection handler
2016/11/15 19:12:14 [debug] 30743#30743: *162 free: 00000F0D34E120F0, unused: 3488
2016/11/15 19:12:14 [debug] 30743#30743: *162 free: 00000F0D34D83A10
2016/11/15 19:12:14 [debug] 30743#30743: *162 reusable connection: 1
2016/11/15 19:12:14 [debug] 30743#30743: *162 event timer add: 3: 180000:1479237314600
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 idle handler
2016/11/15 19:12:18 [debug] 30743#30743: *162 reusable connection: 0
2016/11/15 19:12:18 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E03BC0:4096 @16
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 read handler
2016/11/15 19:12:18 [debug] 30743#30743: *162 SSL_read: 1386
2016/11/15 19:12:18 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:12:18 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:12:18 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:12:18 [debug] 30743#30743: *162 SSL_read: 2861
2016/11/15 19:12:18 [debug] 30743#30743: *162 SSL_read: -1
2016/11/15 19:12:18 [debug] 30743#30743: *162 SSL_get_error: 2
2016/11/15 19:12:18 [debug] 30743#30743: *162 process http2 frame type:1 f:24 l:1377 sid:443
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 HEADERS frame sid:443 on 0 excl:0 weight:183
2016/11/15 19:12:18 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E61530:1024 @16
2016/11/15 19:12:18 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E120F0:4096 @16
2016/11/15 19:12:18 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E63480:4096 @16
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 get indexed header name: 3
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 get indexed header name: 75
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 get indexed header name: 7
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 hpack encoded string length: 4
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 hpack encoded string length: 13
2016/11/15 19:12:18 [debug] 30743#30743: *162 http uri: "/appname/v2/heartbeat"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http args: ""
2016/11/15 19:12:18 [debug] 30743#30743: *162 http exten: ""
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 get indexed header: 28
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 hpack encoded string length: 4
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 add header to hpack table: "content-length: 27198"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 hpack table account: 51 free:20
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 http header: "content-length: 27198"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 get indexed header name: 74
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 http header: "accept: application/json, text/plain, */*"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 get indexed header name: 86
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 http header: "origin: https://app3.mydomain.local"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 get indexed header name: 64
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 http header: "appname-csrf-token: YYY
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 get indexed header name: 70
2016/11/15 19:12:18 [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:12:18 [debug] 30743#30743: *162 http2 get indexed header name: 85
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 http header: "content-type: application/json;charset=UTF-8"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 get indexed header name: 83
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 http header: "accept-encoding: gzip, deflate, br"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 get indexed header: 17
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 hpack encoded string length: 11
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 add header to hpack table: "accept-language: en-US,en;q=0.8"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 hpack table account: 61 free:30
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 http header: "accept-language: en-US,en;q=0.8"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 get indexed header: 32
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 hpack encoded string length: 5
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 add header to hpack table: "cookie: XXX"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 hpack table account: 44 free:13
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 get indexed header: 32
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 hpack encoded string length: 662
2016/11/15 19:12:18 [debug] 30743#30743: *162 malloc: 00000F0D34DB5070:1060
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 add header to hpack table: "cookie: XXX"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 hpack table account: 873 free:842
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 get indexed header: 32
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 hpack encoded string length: 622
2016/11/15 19:12:18 [debug] 30743#30743: *162 malloc: 00000F0D34E16F00:996
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 add header to hpack table: "cookie: XXX"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 hpack table account: 918 free:887
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 get indexed header: 32
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 hpack encoded string length: 22
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 add header to hpack table: "cookie: XXX"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 hpack table account: 68 free:37
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 get indexed header name: 68
2016/11/15 19:12:18 [debug] 30743#30743: *162 http2 http request line: "POST /appname/v2/heartbeat HTTP/2.0"
2016/11/15 19:12:18 [debug] 30743#30743: *162 generic phase: 0
2016/11/15 19:12:18 [debug] 30743#30743: *162 rewrite phase: 1
2016/11/15 19:12:18 [debug] 30743#30743: *162 test location: "^/widgets/$"
2016/11/15 19:12:18 [debug] 30743#30743: *162 test location: "/"
2016/11/15 19:12:18 [debug] 30743#30743: *162 test location: "docs/"
2016/11/15 19:12:18 [debug] 30743#30743: *162 test location: "appname/socket"
2016/11/15 19:12:18 [debug] 30743#30743: *162 test location: ~ "^/(index.html)?$"
2016/11/15 19:12:18 [debug] 30743#30743: *162 test location: ~ "^/login/?$"
2016/11/15 19:12:18 [debug] 30743#30743: *162 test location: ~ "^/(appname)"
2016/11/15 19:12:18 [debug] 30743#30743: *162 test location: ~ "/components/(.*)"
2016/11/15 19:12:18 [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:12:18 [debug] 30743#30743: *162 using configuration "/"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http cl:27198 max:1073741824
2016/11/15 19:12:18 [debug] 30743#30743: *162 rewrite phase: 3
2016/11/15 19:12:18 [debug] 30743#30743: *162 post rewrite phase: 4
2016/11/15 19:12:18 [debug] 30743#30743: *162 generic phase: 5
2016/11/15 19:12:18 [debug] 30743#30743: *162 generic phase: 6
2016/11/15 19:12:18 [debug] 30743#30743: *162 generic phase: 7
2016/11/15 19:12:18 [debug] 30743#30743: *162 access phase: 8
2016/11/15 19:12:18 [debug] 30743#30743: *162 access phase: 9
2016/11/15 19:12:18 [debug] 30743#30743: *162 access phase: 10
2016/11/15 19:12:18 [debug] 30743#30743: *162 auth request handler
2016/11/15 19:12:18 [debug] 30743#30743: *162 posix_memalign: 00000F0D34EB6570:4096 @16
2016/11/15 19:12:18 [debug] 30743#30743: *162 http subrequest "/authorize?"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http posted request: "/authorize?"
2016/11/15 19:12:18 [debug] 30743#30743: *162 rewrite phase: 1
2016/11/15 19:12:18 [debug] 30743#30743: *162 test location: "^/widgets/$"
2016/11/15 19:12:18 [debug] 30743#30743: *162 test location: "/"
2016/11/15 19:12:18 [debug] 30743#30743: *162 test location: "docs/"
2016/11/15 19:12:18 [debug] 30743#30743: *162 test location: "dashboard"
2016/11/15 19:12:18 [debug] 30743#30743: *162 test location: "authorize"
2016/11/15 19:12:18 [debug] 30743#30743: *162 using configuration "=/authorize"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http cl:27198 max:1073741824
2016/11/15 19:12:18 [debug] 30743#30743: *162 rewrite phase: 3
2016/11/15 19:12:18 [debug] 30743#30743: *162 post rewrite phase: 4
2016/11/15 19:12:18 [debug] 30743#30743: *162 generic phase: 5
2016/11/15 19:12:18 [debug] 30743#30743: *162 generic phase: 6
2016/11/15 19:12:18 [debug] 30743#30743: *162 generic phase: 7
2016/11/15 19:12:18 [debug] 30743#30743: *162 http init upstream, client timer: 0
2016/11/15 19:12:18 [debug] 30743#30743: *162 posix_memalign: 00000F0D34EB7580:4096 @16
2016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: "X-Real-IP: "
2016/11/15 19:12:18 [debug] 30743#30743: *162 http script var: "192.168.123.11"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: "X-Forwarded-For: "
2016/11/15 19:12:18 [debug] 30743#30743: *162 http script var: "192.168.123.11"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: "Host: "
2016/11/15 19:12:18 [debug] 30743#30743: *162 http script var: "app3.mydomain.local"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: "X-NginX-Proxy: true
"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: "X-Client-S-DN: "
2016/11/15 19:12:18 [debug] 30743#30743: *162 http script var: "XXX"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: "X-Client-Serial: "
2016/11/15 19:12:18 [debug] 30743#30743: *162 http script var: "XXXX"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: "x-appname-uri: "
2016/11/15 19:12:18 [debug] 30743#30743: *162 http script var: "/appname/v2/heartbeat"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: "x-appname-method: "
2016/11/15 19:12:18 [debug] 30743#30743: *162 http script var: "POST"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: "
"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: "Connection: close
"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: ""
2016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: ""
2016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy header: "accept: application/json, text/plain, */*"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy header: "origin: https://app3.mydomain.local"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy header: "appname-csrf-token: YYY
2016/11/15 19:12:18 [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:12:18 [debug] 30743#30743: *162 http proxy header: "content-type: application/json;charset=UTF-8"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy header: "accept-encoding: gzip, deflate, br"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy header: "accept-language: en-US,en;q=0.8"
2016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy header: "cookie: XXX"
2016/11/15 19:12:18 [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