Ticket #1128: app-error-log3.txt

File app-error-log3.txt, 86.2 KB (added by kcannon.gaikai.com@…, 10 years ago)
Line 
12016/11/15 19:12:18 [debug] 30743#30743: *162 http cleanup add: 00000F0D34E64460
22016/11/15 19:12:18 [debug] 30743#30743: *162 get rr peer, try: 1
32016/11/15 19:12:18 [debug] 30743#30743: *162 stream socket 7
42016/11/15 19:12:18 [debug] 30743#30743: *162 epoll add connection: fd:7 ev:80002005
52016/11/15 19:12:18 [debug] 30743#30743: *162 connect to 127.0.0.1:8008, fd:7 #585
62016/11/15 19:12:18 [debug] 30743#30743: *162 http upstream connect: -2
72016/11/15 19:12:18 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBBA30:128 @16
82016/11/15 19:12:18 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237198707
92016/11/15 19:12:18 [debug] 30743#30743: *162 http finalize request: -4, "/authorize?" a:1, c:3
102016/11/15 19:12:18 [debug] 30743#30743: *162 http request count:3 blk:0
112016/11/15 19:12:18 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AC57A end:00006EFC4F5AF22E
122016/11/15 19:12:18 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:443
132016/11/15 19:12:18 [debug] 30743#30743: *162 http2 DATA frame
142016/11/15 19:12:18 [debug] 30743#30743: *162 malloc: 00000F0D34D89720:65536
152016/11/15 19:12:18 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AD0A7 end:00006EFC4F5AF22E
162016/11/15 19:12:18 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:443
172016/11/15 19:12:18 [debug] 30743#30743: *162 http2 DATA frame
182016/11/15 19:12:18 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5ADBD4 end:00006EFC4F5AF22E
192016/11/15 19:12:18 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:443
202016/11/15 19:12:18 [debug] 30743#30743: *162 http2 DATA frame
212016/11/15 19:12:18 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AE701 end:00006EFC4F5AF22E
222016/11/15 19:12:18 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:443
232016/11/15 19:12:18 [debug] 30743#30743: *162 http2 DATA frame
242016/11/15 19:12:18 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AF22E end:00006EFC4F5AF22E
252016/11/15 19:12:18 [debug] 30743#30743: *162 event timer del: 3: 1479237314600
262016/11/15 19:12:18 [debug] 30743#30743: *162 http2 write handler
272016/11/15 19:12:18 [debug] 30743#30743: *162 http2 read handler
282016/11/15 19:12:18 [debug] 30743#30743: *162 SSL_read: 2861
292016/11/15 19:12:18 [debug] 30743#30743: *162 SSL_read: 2861
302016/11/15 19:12:18 [debug] 30743#30743: *162 SSL_read: 2861
312016/11/15 19:12:18 [debug] 30743#30743: *162 SSL_read: 2861
322016/11/15 19:12:18 [debug] 30743#30743: *162 SSL_read: 2861
332016/11/15 19:12:18 [debug] 30743#30743: *162 SSL_read: 1539
342016/11/15 19:12:18 [debug] 30743#30743: *162 SSL_read: -1
352016/11/15 19:12:18 [debug] 30743#30743: *162 SSL_get_error: 2
362016/11/15 19:12:18 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:443
372016/11/15 19:12:18 [debug] 30743#30743: *162 http2 DATA frame
382016/11/15 19:12:18 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5ACB3D end:00006EFC4F5AFDF4
392016/11/15 19:12:18 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:443
402016/11/15 19:12:18 [debug] 30743#30743: *162 http2 DATA frame
412016/11/15 19:12:18 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AD66A end:00006EFC4F5AFDF4
422016/11/15 19:12:18 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:443
432016/11/15 19:12:18 [debug] 30743#30743: *162 http2 DATA frame
442016/11/15 19:12:18 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AE197 end:00006EFC4F5AFDF4
452016/11/15 19:12:18 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:443
462016/11/15 19:12:18 [debug] 30743#30743: *162 http2 DATA frame
472016/11/15 19:12:18 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AECC4 end:00006EFC4F5AFDF4
482016/11/15 19:12:18 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:443
492016/11/15 19:12:18 [debug] 30743#30743: *162 http2 DATA frame
502016/11/15 19:12:18 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AF7F1 end:00006EFC4F5AFDF4
512016/11/15 19:12:18 [debug] 30743#30743: *162 process http2 frame type:0 f:1 l:1530 sid:443
522016/11/15 19:12:18 [debug] 30743#30743: *162 http2 DATA frame
532016/11/15 19:12:18 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AFDF4 end:00006EFC4F5AFDF4
542016/11/15 19:12:18 [debug] 30743#30743: *162 http2 write handler
552016/11/15 19:12:18 [debug] 30743#30743: *162 http upstream request: "/authorize?"
562016/11/15 19:12:18 [debug] 30743#30743: *162 http upstream send request handler
572016/11/15 19:12:18 [debug] 30743#30743: *162 http upstream send request
582016/11/15 19:12:18 [debug] 30743#30743: *162 http upstream send request body
592016/11/15 19:12:18 [debug] 30743#30743: *162 chain writer buf fl:1 s:2711
602016/11/15 19:12:18 [debug] 30743#30743: *162 chain writer in: 00000F0D34EB7550
612016/11/15 19:12:18 [debug] 30743#30743: *162 writev: 2711 of 2711
622016/11/15 19:12:18 [debug] 30743#30743: *162 chain writer out: 0000000000000000
632016/11/15 19:12:18 [debug] 30743#30743: *162 event timer del: 7: 1479237198707
642016/11/15 19:12:18 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237198708
652016/11/15 19:12:18 [debug] 30743#30743: *162 http upstream request: "/authorize?"
662016/11/15 19:12:18 [debug] 30743#30743: *162 http upstream process header
672016/11/15 19:12:18 [debug] 30743#30743: *162 malloc: 00000F0D34DBC950:4096
682016/11/15 19:12:18 [debug] 30743#30743: *162 recv: fd:7 172 of 4096
692016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy status 200 "200 OK"
702016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy header: "X-Powered-By: Express"
712016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy header: "x-appname-origin: appname3"
722016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy header: "content-type: application/json"
732016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy header: "content-length: 0"
742016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy header: "Date: Tue, 15 Nov 2016 19:12:18 GMT"
752016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy header: "Connection: close"
762016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy header done
772016/11/15 19:12:18 [debug] 30743#30743: *162 lua capture header filter, uri "/authorize"
782016/11/15 19:12:18 [debug] 30743#30743: *162 http2 header filter
792016/11/15 19:12:18 [debug] 30743#30743: *162 finalize http upstream request: 0
802016/11/15 19:12:18 [debug] 30743#30743: *162 finalize http proxy request
812016/11/15 19:12:18 [debug] 30743#30743: *162 free rr peer 1 0
822016/11/15 19:12:18 [debug] 30743#30743: *162 close http upstream connection: 7
832016/11/15 19:12:18 [debug] 30743#30743: *162 free: 00000F0D34DBBA30, unused: 48
842016/11/15 19:12:18 [debug] 30743#30743: *162 event timer del: 7: 1479237198708
852016/11/15 19:12:18 [debug] 30743#30743: *162 reusable connection: 0
862016/11/15 19:12:18 [debug] 30743#30743: *162 http finalize request: 0, "/authorize?" a:1, c:2
872016/11/15 19:12:18 [debug] 30743#30743: *162 auth request done s:200
882016/11/15 19:12:18 [debug] 30743#30743: *162 http wake parent request: "/appname/v2/heartbeat?"
892016/11/15 19:12:18 [debug] 30743#30743: *162 http posted request: "/appname/v2/heartbeat?"
902016/11/15 19:12:18 [debug] 30743#30743: *162 access phase: 10
912016/11/15 19:12:18 [debug] 30743#30743: *162 auth request handler
922016/11/15 19:12:18 [debug] 30743#30743: *162 auth request set variables
932016/11/15 19:12:18 [debug] 30743#30743: *162 access phase: 11
942016/11/15 19:12:18 [debug] 30743#30743: *162 lua access handler, uri:"/appname/v2/heartbeat" c:1
952016/11/15 19:12:18 [debug] 30743#30743: *162 post access phase: 12
962016/11/15 19:12:18 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBD960:4096 @16
972016/11/15 19:12:18 [debug] 30743#30743: *162 http body new buf t:1 f:0 00000F0D34D89720, pos 00000F0D34D89720, size: 27198 file: 0, size: 0
982016/11/15 19:12:18 [debug] 30743#30743: *162 http init upstream, client timer: 0
992016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: "X-Real-IP: "
1002016/11/15 19:12:18 [debug] 30743#30743: *162 http script var: "192.168.123.11"
1012016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: "
102"
1032016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: "X-Forwarded-For: "
1042016/11/15 19:12:18 [debug] 30743#30743: *162 http script var: "192.168.123.11"
1052016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: "
106"
1072016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: "Host: "
1082016/11/15 19:12:18 [debug] 30743#30743: *162 http script var: "app3.mydomain.local"
1092016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: "
110"
1112016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: "X-NginX-Proxy: true
112"
1132016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: "X-Client-S-DN: "
1142016/11/15 19:12:18 [debug] 30743#30743: *162 http script var: "XXX"
1152016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: "
116"
1172016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: "X-Client-Serial: "
1182016/11/15 19:12:18 [debug] 30743#30743: *162 http script var: "XXXX"
1192016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: "
120"
1212016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: "Connection: close
122"
1232016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: "Content-Length: "
1242016/11/15 19:12:18 [debug] 30743#30743: *162 http script var: "27198"
1252016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: "
126"
1272016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: ""
1282016/11/15 19:12:18 [debug] 30743#30743: *162 http script copy: ""
1292016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy header: "accept: application/json, text/plain, */*"
1302016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy header: "origin: https://app3.mydomain.local"
1312016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy header: "appname-csrf-token: YYY
1322016/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"
1332016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy header: "content-type: application/json;charset=UTF-8"
1342016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy header: "accept-encoding: gzip, deflate, br"
1352016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy header: "accept-language: en-US,en;q=0.8"
1362016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy header: "cookie: XXX"
1372016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy header:
138"POST /appname/v2/heartbeat HTTP/1.1
139X-Real-IP: 192.168.123.11
140X-Forwarded-For: 192.168.123.11
141Host: app3.mydomain.local
142X-NginX-Proxy: true
143
144
145Connection: close
146Content-Length: 27198
147accept: application/json, text/plain, */*
148origin: https://app3.mydomain.local
149appname-csrf-token: YYY
150user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.75 Safari/537.36
151content-type: application/json;charset=UTF-8
152accept-encoding: gzip, deflate, br
153accept-language: en-US,en;q=0.8
1542016/11/15 19:12:18 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBE970:4096 @16
1552016/11/15 19:12:18 [debug] 30743#30743: *162 http cleanup add: 00000F0D34DBE938
1562016/11/15 19:12:18 [debug] 30743#30743: *162 get rr peer, try: 1
1572016/11/15 19:12:18 [debug] 30743#30743: *162 stream socket 7
1582016/11/15 19:12:18 [debug] 30743#30743: *162 epoll add connection: fd:7 ev:80002005
1592016/11/15 19:12:18 [debug] 30743#30743: *162 connect to 182.168.128.69:8080, fd:7 #586
1602016/11/15 19:12:18 [debug] 30743#30743: *162 http upstream connect: -2
1612016/11/15 19:12:18 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBBA30:128 @16
1622016/11/15 19:12:18 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237198731
1632016/11/15 19:12:18 [debug] 30743#30743: *162 free: 00000F0D34D89720
1642016/11/15 19:12:18 [debug] 30743#30743: *162 http finalize request: -4, "/appname/v2/heartbeat?" a:1, c:2
1652016/11/15 19:12:18 [debug] 30743#30743: *162 http request count:2 blk:0
1662016/11/15 19:12:18 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?"
1672016/11/15 19:12:18 [debug] 30743#30743: *162 http upstream send request handler
1682016/11/15 19:12:18 [debug] 30743#30743: *162 http upstream send request
1692016/11/15 19:12:18 [debug] 30743#30743: *162 http upstream send request body
1702016/11/15 19:12:18 [debug] 30743#30743: *162 chain writer buf fl:0 s:2690
1712016/11/15 19:12:18 [debug] 30743#30743: *162 chain writer buf fl:1 s:27198
1722016/11/15 19:12:18 [debug] 30743#30743: *162 chain writer in: 00000F0D34DBEA00
1732016/11/15 19:12:18 [debug] 30743#30743: *162 writev: 28960 of 29888
1742016/11/15 19:12:18 [debug] 30743#30743: *162 chain writer out: 00000F0D34DBEA10
1752016/11/15 19:12:18 [debug] 30743#30743: *162 event timer: 7, old: 1479237198731, new: 1479237198732
1762016/11/15 19:12:18 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?"
1772016/11/15 19:12:18 [debug] 30743#30743: *162 http upstream send request handler
1782016/11/15 19:12:18 [debug] 30743#30743: *162 http upstream send request
1792016/11/15 19:12:18 [debug] 30743#30743: *162 http upstream send request body
1802016/11/15 19:12:18 [debug] 30743#30743: *162 chain writer in: 00000F0D34DBEA10
1812016/11/15 19:12:18 [debug] 30743#30743: *162 writev: 928 of 928
1822016/11/15 19:12:18 [debug] 30743#30743: *162 chain writer out: 0000000000000000
1832016/11/15 19:12:18 [debug] 30743#30743: *162 event timer del: 7: 1479237198731
1842016/11/15 19:12:18 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237198732
1852016/11/15 19:12:18 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?"
1862016/11/15 19:12:18 [debug] 30743#30743: *162 http upstream process header
1872016/11/15 19:12:18 [debug] 30743#30743: *162 malloc: 00000F0D34D69D00:4096
1882016/11/15 19:12:18 [debug] 30743#30743: *162 recv: fd:7 1056 of 4096
1892016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy status 400 "400 Bad Request"
1902016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy header: "Server: nginx"
1912016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy header: "Date: Tue, 15 Nov 2016 19:12:19 GMT"
1922016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy header: "Content-Type: text/html; charset=utf-8"
1932016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy header: "Content-Length: 840"
1942016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy header: "Connection: close"
1952016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy header: "X-Powered-By: Express"
1962016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy header: "X-Content-Type-Options: nosniff"
1972016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy header done
1982016/11/15 19:12:18 [debug] 30743#30743: *162 lua capture header filter, uri "/appname/v2/heartbeat"
1992016/11/15 19:12:18 [debug] 30743#30743: *162 http2 header filter
2002016/11/15 19:12:18 [debug] 30743#30743: *162 http2 output header: ":status: 400"
2012016/11/15 19:12:18 [debug] 30743#30743: *162 http2 output header: "server: nginx"
2022016/11/15 19:12:18 [debug] 30743#30743: *162 http2 output header: "date: Tue, 15 Nov 2016 19:12:18 GMT"
2032016/11/15 19:12:18 [debug] 30743#30743: *162 http2 output header: "content-type: text/html; charset=utf-8"
2042016/11/15 19:12:18 [debug] 30743#30743: *162 http2 output header: "content-length: 840"
2052016/11/15 19:12:18 [debug] 30743#30743: *162 http2 output header: "x-powered-by: Express"
2062016/11/15 19:12:18 [debug] 30743#30743: *162 http2 output header: "x-content-type-options: nosniff"
2072016/11/15 19:12:18 [debug] 30743#30743: *162 http2:443 create HEADERS frame 00000F0D34DBEDA8: len:98
2082016/11/15 19:12:18 [debug] 30743#30743: *162 http cleanup add: 00000F0D34DBEE90
2092016/11/15 19:12:18 [debug] 30743#30743: *162 http2 frame out: 00000F0D34DBEDA8 sid:443 bl:1 len:98
2102016/11/15 19:12:18 [debug] 30743#30743: *162 malloc: 00000F0D34D83A10:16384
2112016/11/15 19:12:18 [debug] 30743#30743: *162 SSL buf copy: 9
2122016/11/15 19:12:18 [debug] 30743#30743: *162 SSL buf copy: 98
2132016/11/15 19:12:18 [debug] 30743#30743: *162 http2:443 HEADERS frame 00000F0D34DBEDA8 was sent
2142016/11/15 19:12:18 [debug] 30743#30743: *162 http2 frame sent: 00000F0D34DBEDA8 sid:443 bl:1 len:98
2152016/11/15 19:12:18 [debug] 30743#30743: *162 http cacheable: 0
2162016/11/15 19:12:18 [debug] 30743#30743: *162 http proxy filter init s:400 h:0 c:0 l:840
2172016/11/15 19:12:18 [debug] 30743#30743: *162 http upstream process upstream
2182016/11/15 19:12:18 [debug] 30743#30743: *162 pipe read upstream: 1
2192016/11/15 19:12:18 [debug] 30743#30743: *162 pipe preread: 840
2202016/11/15 19:12:18 [debug] 30743#30743: *162 readv: 1, last:3040
2212016/11/15 19:12:18 [debug] 30743#30743: *162 pipe recv chain: 0
2222016/11/15 19:12:18 [debug] 30743#30743: *162 pipe buf free s:0 t:1 f:0 00000F0D34D69D00, pos 00000F0D34D69DD8, size: 840 file: 0, size: 0
2232016/11/15 19:12:18 [debug] 30743#30743: *162 pipe length: 840
2242016/11/15 19:12:18 [debug] 30743#30743: *162 input buf #0
2252016/11/15 19:12:18 [debug] 30743#30743: *162 pipe write downstream: 1
2262016/11/15 19:12:18 [debug] 30743#30743: *162 pipe write downstream flush in
2272016/11/15 19:12:18 [debug] 30743#30743: *162 http output filter "/appname/v2/heartbeat?"
2282016/11/15 19:12:18 [debug] 30743#30743: *162 http copy filter: "/appname/v2/heartbeat?"
2292016/11/15 19:12:18 [debug] 30743#30743: *162 lua capture body filter, uri "/appname/v2/heartbeat"
2302016/11/15 19:12:18 [debug] 30743#30743: *162 http postpone filter "/appname/v2/heartbeat?" 00000F0D34DBEA00
2312016/11/15 19:12:18 [debug] 30743#30743: *162 write new buf t:1 f:0 00000F0D34D69D00, pos 00000F0D34D69DD8, size: 840 file: 0, size: 0
2322016/11/15 19:12:18 [debug] 30743#30743: *162 http write filter: l:0 f:0 s:840
2332016/11/15 19:12:18 [debug] 30743#30743: *162 http copy filter: 0 "/appname/v2/heartbeat?"
2342016/11/15 19:12:18 [debug] 30743#30743: *162 pipe write downstream done
2352016/11/15 19:12:18 [debug] 30743#30743: *162 event timer: 7, old: 1479237198732, new: 1479237198740
2362016/11/15 19:12:18 [debug] 30743#30743: *162 http upstream exit: 0000000000000000
2372016/11/15 19:12:18 [debug] 30743#30743: *162 finalize http upstream request: 0
2382016/11/15 19:12:18 [debug] 30743#30743: *162 finalize http proxy request
2392016/11/15 19:12:18 [debug] 30743#30743: *162 free rr peer 1 0
2402016/11/15 19:12:18 [debug] 30743#30743: *162 close http upstream connection: 7
2412016/11/15 19:12:18 [debug] 30743#30743: *162 free: 00000F0D34DBBA30, unused: 48
2422016/11/15 19:12:18 [debug] 30743#30743: *162 event timer del: 7: 1479237198732
2432016/11/15 19:12:18 [debug] 30743#30743: *162 reusable connection: 0
2442016/11/15 19:12:18 [debug] 30743#30743: *162 http upstream temp fd: -1
2452016/11/15 19:12:18 [debug] 30743#30743: *162 http output filter "/appname/v2/heartbeat?"
2462016/11/15 19:12:18 [debug] 30743#30743: *162 http copy filter: "/appname/v2/heartbeat?"
2472016/11/15 19:12:18 [debug] 30743#30743: *162 lua capture body filter, uri "/appname/v2/heartbeat"
2482016/11/15 19:12:18 [debug] 30743#30743: *162 http postpone filter "/appname/v2/heartbeat?" 00007A9E70E05A50
2492016/11/15 19:12:18 [debug] 30743#30743: *162 write old buf t:1 f:0 00000F0D34D69D00, pos 00000F0D34D69DD8, size: 840 file: 0, size: 0
2502016/11/15 19:12:18 [debug] 30743#30743: *162 write new buf t:0 f:0 0000000000000000, pos 0000000000000000, size: 0 file: 0, size: 0
2512016/11/15 19:12:18 [debug] 30743#30743: *162 http write filter: l:1 f:0 s:840
2522016/11/15 19:12:18 [debug] 30743#30743: *162 http write filter limit 0
2532016/11/15 19:12:18 [debug] 30743#30743: *162 http2:443 create DATA frame 00000F0D34DBEDA8: len:840 flags:1
2542016/11/15 19:12:18 [debug] 30743#30743: *162 http2 frame out: 00000F0D34DBEDA8 sid:443 bl:0 len:840
2552016/11/15 19:12:18 [debug] 30743#30743: *162 SSL buf copy: 9
2562016/11/15 19:12:18 [debug] 30743#30743: *162 SSL buf copy: 840
2572016/11/15 19:12:18 [debug] 30743#30743: *162 SSL to write: 956
2582016/11/15 19:12:18 [debug] 30743#30743: *162 SSL_write: 956
2592016/11/15 19:12:18 [debug] 30743#30743: *162 http2:443 DATA frame 00000F0D34DBEDA8 was sent
2602016/11/15 19:12:18 [debug] 30743#30743: *162 http2 frame sent: 00000F0D34DBEDA8 sid:443 bl:0 len:840
2612016/11/15 19:12:18 [debug] 30743#30743: *162 http write filter 0000000000000000
2622016/11/15 19:12:18 [debug] 30743#30743: *162 http copy filter: 0 "/appname/v2/heartbeat?"
2632016/11/15 19:12:18 [debug] 30743#30743: *162 http finalize request: 0, "/appname/v2/heartbeat?" a:1, c:1
2642016/11/15 19:12:18 [debug] 30743#30743: *162 http request count:1 blk:0
2652016/11/15 19:12:18 [debug] 30743#30743: *162 http2 close stream 443, queued 0, processing 1
2662016/11/15 19:12:18 [debug] 30743#30743: *162 http close request
2672016/11/15 19:12:18 [debug] 30743#30743: *162 http log handler
2682016/11/15 19:12:18 [debug] 30743#30743: *162 free: 00000F0D34DBC950
2692016/11/15 19:12:18 [debug] 30743#30743: *162 free: 00000F0D34D69D00
2702016/11/15 19:12:18 [debug] 30743#30743: *162 free: 00000F0D34E120F0, unused: 0
2712016/11/15 19:12:18 [debug] 30743#30743: *162 free: 00000F0D34E63480, unused: 2
2722016/11/15 19:12:18 [debug] 30743#30743: *162 free: 00000F0D34EB6570, unused: 0
2732016/11/15 19:12:18 [debug] 30743#30743: *162 free: 00000F0D34EB7580, unused: 8
2742016/11/15 19:12:18 [debug] 30743#30743: *162 free: 00000F0D34DBD960, unused: 0
2752016/11/15 19:12:18 [debug] 30743#30743: *162 free: 00000F0D34DBE970, unused: 1926
2762016/11/15 19:12:18 [debug] 30743#30743: *162 free: 00000F0D34E16F00
2772016/11/15 19:12:18 [debug] 30743#30743: *162 free: 00000F0D34DB5070
2782016/11/15 19:12:18 [debug] 30743#30743: *162 free: 00000F0D34E61530, unused: 164
2792016/11/15 19:12:18 [debug] 30743#30743: *162 post event 00006EFC4C5081F0
2802016/11/15 19:12:18 [debug] 30743#30743: *162 delete posted event 00006EFC4C5081F0
2812016/11/15 19:12:18 [debug] 30743#30743: *162 http2 handle connection handler
2822016/11/15 19:12:18 [debug] 30743#30743: *162 free: 00000F0D34E03BC0, unused: 3488
2832016/11/15 19:12:18 [debug] 30743#30743: *162 free: 00000F0D34D83A10
2842016/11/15 19:12:18 [debug] 30743#30743: *162 reusable connection: 1
2852016/11/15 19:12:18 [debug] 30743#30743: *162 event timer add: 3: 180000:1479237318740
2862016/11/15 19:12:22 [debug] 30741#30741: *300 post event 00006EFC4C5082B0
2872016/11/15 19:12:22 [debug] 30741#30741: *300 post event 00006EFC4C2072B0
2882016/11/15 19:12:22 [debug] 30741#30741: *300 delete posted event 00006EFC4C5082B0
2892016/11/15 19:12:22 [debug] 30741#30741: *300 http run request: "/appname/socket/?EIO=3&transport=websocket&sid=fJvr3YafvdqAy4F3AAAC"
2902016/11/15 19:12:22 [debug] 30741#30741: *300 http upstream process upgraded, fu:0
2912016/11/15 19:12:22 [debug] 30741#30741: *300 SSL_read: 9
2922016/11/15 19:12:22 [debug] 30741#30741: *300 SSL_read: -1
2932016/11/15 19:12:22 [debug] 30741#30741: *300 SSL_get_error: 2
2942016/11/15 19:12:22 [debug] 30741#30741: *300 send: fd:16 9 of 9
2952016/11/15 19:12:22 [debug] 30741#30741: *300 event timer del: 16: 1479237177561
2962016/11/15 19:12:22 [debug] 30741#30741: *300 event timer add: 16: 60000:1479237202565
2972016/11/15 19:12:22 [debug] 30741#30741: *300 delete posted event 00006EFC4C2072B0
2982016/11/15 19:12:22 [debug] 30741#30741: *300 http run request: "/appname/socket/?EIO=3&transport=websocket&sid=fJvr3YafvdqAy4F3AAAC"
2992016/11/15 19:12:22 [debug] 30741#30741: *300 http upstream process upgraded, fu:1
3002016/11/15 19:12:22 [debug] 30741#30741: *300 event timer: 16, old: 1479237202565, new: 1479237202565
3012016/11/15 19:12:22 [debug] 30741#30741: *300 post event 00006EFC4C508310
3022016/11/15 19:12:22 [debug] 30741#30741: *300 post event 00006EFC4C207310
3032016/11/15 19:12:22 [debug] 30741#30741: *300 delete posted event 00006EFC4C508310
3042016/11/15 19:12:22 [debug] 30741#30741: *300 http upstream request: "/appname/socket/?EIO=3&transport=websocket&sid=fJvr3YafvdqAy4F3AAAC"
3052016/11/15 19:12:22 [debug] 30741#30741: *300 http upstream process upgraded, fu:1
3062016/11/15 19:12:22 [debug] 30741#30741: *300 recv: fd:16 3 of 4096
3072016/11/15 19:12:22 [debug] 30741#30741: *300 SSL to write: 3
3082016/11/15 19:12:22 [debug] 30741#30741: *300 SSL_write: 3
3092016/11/15 19:12:22 [debug] 30741#30741: *300 recv: fd:16 -1 of 4096
3102016/11/15 19:12:22 [debug] 30741#30741: *300 recv() not ready (11: Resource temporarily unavailable)
3112016/11/15 19:12:22 [debug] 30741#30741: *300 event timer: 16, old: 1479237202565, new: 1479237202570
3122016/11/15 19:12:22 [debug] 30741#30741: *300 delete posted event 00006EFC4C207310
3132016/11/15 19:12:22 [debug] 30741#30741: *300 http upstream request: "/appname/socket/?EIO=3&transport=websocket&sid=fJvr3YafvdqAy4F3AAAC"
3142016/11/15 19:12:22 [debug] 30741#30741: *300 http upstream process upgraded, fu:0
3152016/11/15 19:12:22 [debug] 30741#30741: *300 event timer: 16, old: 1479237202565, new: 1479237202570
3162016/11/15 19:12:25 [debug] 30743#30743: *162 http2 idle handler
3172016/11/15 19:12:25 [debug] 30743#30743: *162 reusable connection: 0
3182016/11/15 19:12:25 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E120F0:4096 @16
3192016/11/15 19:12:25 [debug] 30743#30743: *162 http2 read handler
3202016/11/15 19:12:25 [debug] 30743#30743: *162 SSL_read: 55
3212016/11/15 19:12:25 [debug] 30743#30743: *162 SSL_read: 2861
3222016/11/15 19:12:25 [debug] 30743#30743: *162 SSL_read: 2861
3232016/11/15 19:12:25 [debug] 30743#30743: *162 SSL_read: 2861
3242016/11/15 19:12:25 [debug] 30743#30743: *162 SSL_read: 2861
3252016/11/15 19:12:25 [debug] 30743#30743: *162 SSL_read: -1
3262016/11/15 19:12:25 [debug] 30743#30743: *162 SSL_get_error: 2
3272016/11/15 19:12:25 [debug] 30743#30743: *162 process http2 frame type:1 f:24 l:46 sid:445
3282016/11/15 19:12:25 [debug] 30743#30743: *162 http2 HEADERS frame sid:445 on 0 excl:0 weight:183
3292016/11/15 19:12:25 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E61530:1024 @16
3302016/11/15 19:12:25 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E03BC0:4096 @16
3312016/11/15 19:12:25 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E63480:4096 @16
3322016/11/15 19:12:25 [debug] 30743#30743: *162 http2 get indexed header name: 3
3332016/11/15 19:12:25 [debug] 30743#30743: *162 http2 get indexed header name: 81
3342016/11/15 19:12:25 [debug] 30743#30743: *162 http2 get indexed header name: 7
3352016/11/15 19:12:25 [debug] 30743#30743: *162 http2 hpack encoded string length: 4
3362016/11/15 19:12:25 [debug] 30743#30743: *162 http2 hpack encoded string length: 13
3372016/11/15 19:12:25 [debug] 30743#30743: *162 http uri: "/appname/v2/heartbeat"
3382016/11/15 19:12:25 [debug] 30743#30743: *162 http args: ""
3392016/11/15 19:12:25 [debug] 30743#30743: *162 http exten: ""
3402016/11/15 19:12:25 [debug] 30743#30743: *162 http2 get indexed header: 28
3412016/11/15 19:12:25 [debug] 30743#30743: *162 http2 hpack encoded string length: 4
3422016/11/15 19:12:25 [debug] 30743#30743: *162 http2 add header to hpack table: "content-length: 17225"
3432016/11/15 19:12:25 [debug] 30743#30743: *162 http2 hpack table account: 51 free:18
3442016/11/15 19:12:25 [debug] 30743#30743: *162 http2 http header: "content-length: 17225"
3452016/11/15 19:12:25 [debug] 30743#30743: *162 http2 get indexed header name: 80
3462016/11/15 19:12:25 [debug] 30743#30743: *162 http2 http header: "accept: application/json, text/plain, */*"
3472016/11/15 19:12:25 [debug] 30743#30743: *162 http2 get indexed header name: 92
3482016/11/15 19:12:25 [debug] 30743#30743: *162 http2 http header: "origin: https://app3.mydomain.local"
3492016/11/15 19:12:25 [debug] 30743#30743: *162 http2 get indexed header name: 70
3502016/11/15 19:12:25 [debug] 30743#30743: *162 http2 http header: "appname-csrf-token: YYY
3512016/11/15 19:12:25 [debug] 30743#30743: *162 http2 get indexed header name: 76
3522016/11/15 19:12:25 [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"
3532016/11/15 19:12:25 [debug] 30743#30743: *162 http2 get indexed header name: 91
3542016/11/15 19:12:25 [debug] 30743#30743: *162 http2 http header: "content-type: application/json;charset=UTF-8"
3552016/11/15 19:12:25 [debug] 30743#30743: *162 http2 get indexed header name: 89
3562016/11/15 19:12:25 [debug] 30743#30743: *162 http2 http header: "accept-encoding: gzip, deflate, br"
3572016/11/15 19:12:25 [debug] 30743#30743: *162 http2 get indexed header name: 67
3582016/11/15 19:12:25 [debug] 30743#30743: *162 http2 http header: "accept-language: en-US,en;q=0.8"
3592016/11/15 19:12:25 [debug] 30743#30743: *162 http2 get indexed header name: 66
3602016/11/15 19:12:25 [debug] 30743#30743: *162 http2 get indexed header name: 65
3612016/11/15 19:12:25 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E16F00:1024 @16
3622016/11/15 19:12:25 [debug] 30743#30743: *162 http2 get indexed header name: 64
3632016/11/15 19:12:25 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DC4930:1024 @16
3642016/11/15 19:12:25 [debug] 30743#30743: *162 http2 get indexed header name: 63
3652016/11/15 19:12:25 [debug] 30743#30743: *162 http2 get indexed header name: 69
3662016/11/15 19:12:25 [debug] 30743#30743: *162 http2 http request line: "POST /appname/v2/heartbeat HTTP/2.0"
3672016/11/15 19:12:25 [debug] 30743#30743: *162 generic phase: 0
3682016/11/15 19:12:25 [debug] 30743#30743: *162 rewrite phase: 1
3692016/11/15 19:12:25 [debug] 30743#30743: *162 test location: "^/widgets/$"
3702016/11/15 19:12:25 [debug] 30743#30743: *162 test location: "/"
3712016/11/15 19:12:25 [debug] 30743#30743: *162 test location: "docs/"
3722016/11/15 19:12:25 [debug] 30743#30743: *162 test location: "appname/socket"
3732016/11/15 19:12:25 [debug] 30743#30743: *162 test location: ~ "^/(index.html)?$"
3742016/11/15 19:12:25 [debug] 30743#30743: *162 test location: ~ "^/login/?$"
3752016/11/15 19:12:25 [debug] 30743#30743: *162 test location: ~ "^/(appname)"
3762016/11/15 19:12:25 [debug] 30743#30743: *162 test location: ~ "/components/(.*)"
3772016/11/15 19:12:25 [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)$"
3782016/11/15 19:12:25 [debug] 30743#30743: *162 using configuration "/"
3792016/11/15 19:12:25 [debug] 30743#30743: *162 http cl:17225 max:1073741824
3802016/11/15 19:12:25 [debug] 30743#30743: *162 rewrite phase: 3
3812016/11/15 19:12:25 [debug] 30743#30743: *162 post rewrite phase: 4
3822016/11/15 19:12:25 [debug] 30743#30743: *162 generic phase: 5
3832016/11/15 19:12:25 [debug] 30743#30743: *162 generic phase: 6
3842016/11/15 19:12:25 [debug] 30743#30743: *162 generic phase: 7
3852016/11/15 19:12:25 [debug] 30743#30743: *162 access phase: 8
3862016/11/15 19:12:25 [debug] 30743#30743: *162 access phase: 9
3872016/11/15 19:12:25 [debug] 30743#30743: *162 access phase: 10
3882016/11/15 19:12:25 [debug] 30743#30743: *162 auth request handler
3892016/11/15 19:12:25 [debug] 30743#30743: *162 posix_memalign: 00000F0D34EB6570:4096 @16
3902016/11/15 19:12:25 [debug] 30743#30743: *162 http subrequest "/authorize?"
3912016/11/15 19:12:25 [debug] 30743#30743: *162 http posted request: "/authorize?"
3922016/11/15 19:12:25 [debug] 30743#30743: *162 rewrite phase: 1
3932016/11/15 19:12:25 [debug] 30743#30743: *162 test location: "^/widgets/$"
3942016/11/15 19:12:25 [debug] 30743#30743: *162 test location: "/"
3952016/11/15 19:12:25 [debug] 30743#30743: *162 test location: "docs/"
3962016/11/15 19:12:25 [debug] 30743#30743: *162 test location: "dashboard"
3972016/11/15 19:12:25 [debug] 30743#30743: *162 test location: "authorize"
3982016/11/15 19:12:25 [debug] 30743#30743: *162 using configuration "=/authorize"
3992016/11/15 19:12:25 [debug] 30743#30743: *162 http cl:17225 max:1073741824
4002016/11/15 19:12:25 [debug] 30743#30743: *162 rewrite phase: 3
4012016/11/15 19:12:25 [debug] 30743#30743: *162 post rewrite phase: 4
4022016/11/15 19:12:25 [debug] 30743#30743: *162 generic phase: 5
4032016/11/15 19:12:25 [debug] 30743#30743: *162 generic phase: 6
4042016/11/15 19:12:25 [debug] 30743#30743: *162 generic phase: 7
4052016/11/15 19:12:25 [debug] 30743#30743: *162 http init upstream, client timer: 0
4062016/11/15 19:12:25 [debug] 30743#30743: *162 posix_memalign: 00000F0D34EB7580:4096 @16
4072016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: "X-Real-IP: "
4082016/11/15 19:12:25 [debug] 30743#30743: *162 http script var: "192.168.123.11"
4092016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: "
410"
4112016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: "X-Forwarded-For: "
4122016/11/15 19:12:25 [debug] 30743#30743: *162 http script var: "192.168.123.11"
4132016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: "
414"
4152016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: "Host: "
4162016/11/15 19:12:25 [debug] 30743#30743: *162 http script var: "app3.mydomain.local"
4172016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: "
418"
4192016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: "X-NginX-Proxy: true
420"
4212016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: "X-Client-S-DN: "
4222016/11/15 19:12:25 [debug] 30743#30743: *162 http script var: "XXX"
4232016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: "
424"
4252016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: "X-Client-Serial: "
4262016/11/15 19:12:25 [debug] 30743#30743: *162 http script var: "XXXX"
4272016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: "
428"
4292016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: "x-appname-uri: "
4302016/11/15 19:12:25 [debug] 30743#30743: *162 http script var: "/appname/v2/heartbeat"
4312016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: "
432"
4332016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: "x-appname-method: "
4342016/11/15 19:12:25 [debug] 30743#30743: *162 http script var: "POST"
4352016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: "
436"
4372016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: "Connection: close
438"
4392016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: ""
4402016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: ""
4412016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy header: "accept: application/json, text/plain, */*"
4422016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy header: "origin: https://app3.mydomain.local"
4432016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy header: "appname-csrf-token: YYY
4442016/11/15 19:12:25 [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"
4452016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy header: "content-type: application/json;charset=UTF-8"
4462016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy header: "accept-encoding: gzip, deflate, br"
4472016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy header: "accept-language: en-US,en;q=0.8"
4482016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy header: "cookie: XXX"
4492016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy header:
450"GET /authorize HTTP/1.1
451X-Real-IP: 192.168.123.11
452X-Forwarded-For: 192.168.123.11
453Host: app3.mydomain.local
454X-NginX-Proxy: true
455
456
457x-appname-uri: /appname/v2/heartbeat
458x-appname-method: POST
459Connection: close
460accept: application/json, text/plain, */*
461origin: https://app3.mydomain.local
462appname-csrf-token: YYY
463user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.75 Safari/537.36
464content-type: application/json;charset=UTF-8
465accept-encoding: gzip, deflate, br
466accept-language: en-US,en;q=0.8
4672016/11/15 19:12:25 [debug] 30743#30743: *162 http cleanup add: 00000F0D34E64460
4682016/11/15 19:12:25 [debug] 30743#30743: *162 get rr peer, try: 1
4692016/11/15 19:12:25 [debug] 30743#30743: *162 stream socket 7
4702016/11/15 19:12:25 [debug] 30743#30743: *162 epoll add connection: fd:7 ev:80002005
4712016/11/15 19:12:25 [debug] 30743#30743: *162 connect to 127.0.0.1:8008, fd:7 #587
4722016/11/15 19:12:25 [debug] 30743#30743: *162 http upstream connect: -2
4732016/11/15 19:12:25 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBBA30:128 @16
4742016/11/15 19:12:25 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237205567
4752016/11/15 19:12:25 [debug] 30743#30743: *162 http finalize request: -4, "/authorize?" a:1, c:3
4762016/11/15 19:12:25 [debug] 30743#30743: *162 http request count:3 blk:0
4772016/11/15 19:12:25 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AC047 end:00006EFC4F5AECFB
4782016/11/15 19:12:25 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:445
4792016/11/15 19:12:25 [debug] 30743#30743: *162 http2 DATA frame
4802016/11/15 19:12:25 [debug] 30743#30743: *162 malloc: 00000F0D34D89720:65536
4812016/11/15 19:12:25 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5ACB74 end:00006EFC4F5AECFB
4822016/11/15 19:12:25 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:445
4832016/11/15 19:12:25 [debug] 30743#30743: *162 http2 DATA frame
4842016/11/15 19:12:25 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AD6A1 end:00006EFC4F5AECFB
4852016/11/15 19:12:25 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:445
4862016/11/15 19:12:25 [debug] 30743#30743: *162 http2 DATA frame
4872016/11/15 19:12:25 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AE1CE end:00006EFC4F5AECFB
4882016/11/15 19:12:25 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:445
4892016/11/15 19:12:25 [debug] 30743#30743: *162 http2 DATA frame
4902016/11/15 19:12:25 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AECFB end:00006EFC4F5AECFB
4912016/11/15 19:12:25 [debug] 30743#30743: *162 event timer del: 3: 1479237318740
4922016/11/15 19:12:25 [debug] 30743#30743: *162 http2 write handler
4932016/11/15 19:12:25 [debug] 30743#30743: *162 http2 read handler
4942016/11/15 19:12:25 [debug] 30743#30743: *162 SSL_read: 2861
4952016/11/15 19:12:25 [debug] 30743#30743: *162 SSL_read: 2861
4962016/11/15 19:12:25 [debug] 30743#30743: *162 SSL_read: 122
4972016/11/15 19:12:25 [debug] 30743#30743: *162 SSL_read: -1
4982016/11/15 19:12:25 [debug] 30743#30743: *162 SSL_get_error: 2
4992016/11/15 19:12:25 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:445
5002016/11/15 19:12:25 [debug] 30743#30743: *162 http2 DATA frame
5012016/11/15 19:12:25 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5ACB3D end:00006EFC4F5AD6E4
5022016/11/15 19:12:25 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:445
5032016/11/15 19:12:25 [debug] 30743#30743: *162 http2 DATA frame
5042016/11/15 19:12:25 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AD66A end:00006EFC4F5AD6E4
5052016/11/15 19:12:25 [debug] 30743#30743: *162 process http2 frame type:0 f:1 l:113 sid:445
5062016/11/15 19:12:25 [debug] 30743#30743: *162 http2 DATA frame
5072016/11/15 19:12:25 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AD6E4 end:00006EFC4F5AD6E4
5082016/11/15 19:12:25 [debug] 30743#30743: *162 http2 write handler
5092016/11/15 19:12:25 [debug] 30743#30743: *162 http upstream request: "/authorize?"
5102016/11/15 19:12:25 [debug] 30743#30743: *162 http upstream send request handler
5112016/11/15 19:12:25 [debug] 30743#30743: *162 http upstream send request
5122016/11/15 19:12:25 [debug] 30743#30743: *162 http upstream send request body
5132016/11/15 19:12:25 [debug] 30743#30743: *162 chain writer buf fl:1 s:2711
5142016/11/15 19:12:25 [debug] 30743#30743: *162 chain writer in: 00000F0D34EB7550
5152016/11/15 19:12:25 [debug] 30743#30743: *162 writev: 2711 of 2711
5162016/11/15 19:12:25 [debug] 30743#30743: *162 chain writer out: 0000000000000000
5172016/11/15 19:12:25 [debug] 30743#30743: *162 event timer del: 7: 1479237205567
5182016/11/15 19:12:25 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237205570
5192016/11/15 19:12:25 [debug] 30743#30743: *162 http upstream request: "/authorize?"
5202016/11/15 19:12:25 [debug] 30743#30743: *162 http upstream process header
5212016/11/15 19:12:25 [debug] 30743#30743: *162 malloc: 00000F0D34DBC950:4096
5222016/11/15 19:12:25 [debug] 30743#30743: *162 recv: fd:7 172 of 4096
5232016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy status 200 "200 OK"
5242016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy header: "X-Powered-By: Express"
5252016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy header: "x-appname-origin: appname3"
5262016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy header: "content-type: application/json"
5272016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy header: "content-length: 0"
5282016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy header: "Date: Tue, 15 Nov 2016 19:12:25 GMT"
5292016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy header: "Connection: close"
5302016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy header done
5312016/11/15 19:12:25 [debug] 30743#30743: *162 lua capture header filter, uri "/authorize"
5322016/11/15 19:12:25 [debug] 30743#30743: *162 http2 header filter
5332016/11/15 19:12:25 [debug] 30743#30743: *162 finalize http upstream request: 0
5342016/11/15 19:12:25 [debug] 30743#30743: *162 finalize http proxy request
5352016/11/15 19:12:25 [debug] 30743#30743: *162 free rr peer 1 0
5362016/11/15 19:12:25 [debug] 30743#30743: *162 close http upstream connection: 7
5372016/11/15 19:12:25 [debug] 30743#30743: *162 free: 00000F0D34DBBA30, unused: 48
5382016/11/15 19:12:25 [debug] 30743#30743: *162 event timer del: 7: 1479237205570
5392016/11/15 19:12:25 [debug] 30743#30743: *162 reusable connection: 0
5402016/11/15 19:12:25 [debug] 30743#30743: *162 http finalize request: 0, "/authorize?" a:1, c:2
5412016/11/15 19:12:25 [debug] 30743#30743: *162 auth request done s:200
5422016/11/15 19:12:25 [debug] 30743#30743: *162 http wake parent request: "/appname/v2/heartbeat?"
5432016/11/15 19:12:25 [debug] 30743#30743: *162 http posted request: "/appname/v2/heartbeat?"
5442016/11/15 19:12:25 [debug] 30743#30743: *162 access phase: 10
5452016/11/15 19:12:25 [debug] 30743#30743: *162 auth request handler
5462016/11/15 19:12:25 [debug] 30743#30743: *162 auth request set variables
5472016/11/15 19:12:25 [debug] 30743#30743: *162 access phase: 11
5482016/11/15 19:12:25 [debug] 30743#30743: *162 lua access handler, uri:"/appname/v2/heartbeat" c:1
5492016/11/15 19:12:25 [debug] 30743#30743: *162 post access phase: 12
5502016/11/15 19:12:25 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBD960:4096 @16
5512016/11/15 19:12:25 [debug] 30743#30743: *162 http body new buf t:1 f:0 00000F0D34D89720, pos 00000F0D34D89720, size: 17225 file: 0, size: 0
5522016/11/15 19:12:25 [debug] 30743#30743: *162 http init upstream, client timer: 0
5532016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: "X-Real-IP: "
5542016/11/15 19:12:25 [debug] 30743#30743: *162 http script var: "192.168.123.11"
5552016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: "
556"
5572016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: "X-Forwarded-For: "
5582016/11/15 19:12:25 [debug] 30743#30743: *162 http script var: "192.168.123.11"
5592016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: "
560"
5612016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: "Host: "
5622016/11/15 19:12:25 [debug] 30743#30743: *162 http script var: "app3.mydomain.local"
5632016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: "
564"
5652016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: "X-NginX-Proxy: true
566"
5672016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: "X-Client-S-DN: "
5682016/11/15 19:12:25 [debug] 30743#30743: *162 http script var: "XXX"
5692016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: "
570"
5712016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: "X-Client-Serial: "
5722016/11/15 19:12:25 [debug] 30743#30743: *162 http script var: "XXXX"
5732016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: "
574"
5752016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: "Connection: close
576"
5772016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: "Content-Length: "
5782016/11/15 19:12:25 [debug] 30743#30743: *162 http script var: "17225"
5792016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: "
580"
5812016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: ""
5822016/11/15 19:12:25 [debug] 30743#30743: *162 http script copy: ""
5832016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy header: "accept: application/json, text/plain, */*"
5842016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy header: "origin: https://app3.mydomain.local"
5852016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy header: "appname-csrf-token: YYY
5862016/11/15 19:12:25 [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"
5872016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy header: "content-type: application/json;charset=UTF-8"
5882016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy header: "accept-encoding: gzip, deflate, br"
5892016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy header: "accept-language: en-US,en;q=0.8"
5902016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy header: "cookie: XXX"
5912016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy header:
592"POST /appname/v2/heartbeat HTTP/1.1
593X-Real-IP: 192.168.123.11
594X-Forwarded-For: 192.168.123.11
595Host: app3.mydomain.local
596X-NginX-Proxy: true
597
598
599Connection: close
600Content-Length: 17225
601accept: application/json, text/plain, */*
602origin: https://app3.mydomain.local
603appname-csrf-token: YYY
604user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.75 Safari/537.36
605content-type: application/json;charset=UTF-8
606accept-encoding: gzip, deflate, br
607accept-language: en-US,en;q=0.8
6082016/11/15 19:12:25 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBE970:4096 @16
6092016/11/15 19:12:25 [debug] 30743#30743: *162 http cleanup add: 00000F0D34DBE938
6102016/11/15 19:12:25 [debug] 30743#30743: *162 get rr peer, try: 1
6112016/11/15 19:12:25 [debug] 30743#30743: *162 stream socket 7
6122016/11/15 19:12:25 [debug] 30743#30743: *162 epoll add connection: fd:7 ev:80002005
6132016/11/15 19:12:25 [debug] 30743#30743: *162 connect to 182.168.128.69:8080, fd:7 #588
6142016/11/15 19:12:25 [debug] 30743#30743: *162 http upstream connect: -2
6152016/11/15 19:12:25 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBBA30:128 @16
6162016/11/15 19:12:25 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237205592
6172016/11/15 19:12:25 [debug] 30743#30743: *162 free: 00000F0D34D89720
6182016/11/15 19:12:25 [debug] 30743#30743: *162 http finalize request: -4, "/appname/v2/heartbeat?" a:1, c:2
6192016/11/15 19:12:25 [debug] 30743#30743: *162 http request count:2 blk:0
6202016/11/15 19:12:25 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?"
6212016/11/15 19:12:25 [debug] 30743#30743: *162 http upstream send request handler
6222016/11/15 19:12:25 [debug] 30743#30743: *162 http upstream send request
6232016/11/15 19:12:25 [debug] 30743#30743: *162 http upstream send request body
6242016/11/15 19:12:25 [debug] 30743#30743: *162 chain writer buf fl:0 s:2690
6252016/11/15 19:12:25 [debug] 30743#30743: *162 chain writer buf fl:1 s:17225
6262016/11/15 19:12:25 [debug] 30743#30743: *162 chain writer in: 00000F0D34DBEA00
6272016/11/15 19:12:25 [debug] 30743#30743: *162 writev: 19915 of 19915
6282016/11/15 19:12:25 [debug] 30743#30743: *162 chain writer out: 0000000000000000
6292016/11/15 19:12:25 [debug] 30743#30743: *162 event timer del: 7: 1479237205592
6302016/11/15 19:12:25 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237205593
6312016/11/15 19:12:25 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?"
6322016/11/15 19:12:25 [debug] 30743#30743: *162 http upstream process header
6332016/11/15 19:12:25 [debug] 30743#30743: *162 malloc: 00000F0D34D69D00:4096
6342016/11/15 19:12:25 [debug] 30743#30743: *162 recv: fd:7 1056 of 4096
6352016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy status 400 "400 Bad Request"
6362016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy header: "Server: nginx"
6372016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy header: "Date: Tue, 15 Nov 2016 19:12:25 GMT"
6382016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy header: "Content-Type: text/html; charset=utf-8"
6392016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy header: "Content-Length: 840"
6402016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy header: "Connection: close"
6412016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy header: "X-Powered-By: Express"
6422016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy header: "X-Content-Type-Options: nosniff"
6432016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy header done
6442016/11/15 19:12:25 [debug] 30743#30743: *162 lua capture header filter, uri "/appname/v2/heartbeat"
6452016/11/15 19:12:25 [debug] 30743#30743: *162 http2 header filter
6462016/11/15 19:12:25 [debug] 30743#30743: *162 http2 output header: ":status: 400"
6472016/11/15 19:12:25 [debug] 30743#30743: *162 http2 output header: "server: nginx"
6482016/11/15 19:12:25 [debug] 30743#30743: *162 http2 output header: "date: Tue, 15 Nov 2016 19:12:25 GMT"
6492016/11/15 19:12:25 [debug] 30743#30743: *162 http2 output header: "content-type: text/html; charset=utf-8"
6502016/11/15 19:12:25 [debug] 30743#30743: *162 http2 output header: "content-length: 840"
6512016/11/15 19:12:25 [debug] 30743#30743: *162 http2 output header: "x-powered-by: Express"
6522016/11/15 19:12:25 [debug] 30743#30743: *162 http2 output header: "x-content-type-options: nosniff"
6532016/11/15 19:12:25 [debug] 30743#30743: *162 http2:445 create HEADERS frame 00000F0D34DBEDA8: len:98
6542016/11/15 19:12:25 [debug] 30743#30743: *162 http cleanup add: 00000F0D34DBEE90
6552016/11/15 19:12:25 [debug] 30743#30743: *162 http2 frame out: 00000F0D34DBEDA8 sid:445 bl:1 len:98
6562016/11/15 19:12:25 [debug] 30743#30743: *162 malloc: 00000F0D34D83A10:16384
6572016/11/15 19:12:25 [debug] 30743#30743: *162 SSL buf copy: 9
6582016/11/15 19:12:25 [debug] 30743#30743: *162 SSL buf copy: 98
6592016/11/15 19:12:25 [debug] 30743#30743: *162 http2:445 HEADERS frame 00000F0D34DBEDA8 was sent
6602016/11/15 19:12:25 [debug] 30743#30743: *162 http2 frame sent: 00000F0D34DBEDA8 sid:445 bl:1 len:98
6612016/11/15 19:12:25 [debug] 30743#30743: *162 http cacheable: 0
6622016/11/15 19:12:25 [debug] 30743#30743: *162 http proxy filter init s:400 h:0 c:0 l:840
6632016/11/15 19:12:25 [debug] 30743#30743: *162 http upstream process upstream
6642016/11/15 19:12:25 [debug] 30743#30743: *162 pipe read upstream: 1
6652016/11/15 19:12:25 [debug] 30743#30743: *162 pipe preread: 840
6662016/11/15 19:12:25 [debug] 30743#30743: *162 readv: 1, last:3040
6672016/11/15 19:12:25 [debug] 30743#30743: *162 pipe recv chain: 0
6682016/11/15 19:12:25 [debug] 30743#30743: *162 pipe buf free s:0 t:1 f:0 00000F0D34D69D00, pos 00000F0D34D69DD8, size: 840 file: 0, size: 0
6692016/11/15 19:12:25 [debug] 30743#30743: *162 pipe length: 840
6702016/11/15 19:12:25 [debug] 30743#30743: *162 input buf #0
6712016/11/15 19:12:25 [debug] 30743#30743: *162 pipe write downstream: 1
6722016/11/15 19:12:25 [debug] 30743#30743: *162 pipe write downstream flush in
6732016/11/15 19:12:25 [debug] 30743#30743: *162 http output filter "/appname/v2/heartbeat?"
6742016/11/15 19:12:25 [debug] 30743#30743: *162 http copy filter: "/appname/v2/heartbeat?"
6752016/11/15 19:12:25 [debug] 30743#30743: *162 lua capture body filter, uri "/appname/v2/heartbeat"
6762016/11/15 19:12:25 [debug] 30743#30743: *162 http postpone filter "/appname/v2/heartbeat?" 00000F0D34DBEA00
6772016/11/15 19:12:25 [debug] 30743#30743: *162 write new buf t:1 f:0 00000F0D34D69D00, pos 00000F0D34D69DD8, size: 840 file: 0, size: 0
6782016/11/15 19:12:25 [debug] 30743#30743: *162 http write filter: l:0 f:0 s:840
6792016/11/15 19:12:25 [debug] 30743#30743: *162 http copy filter: 0 "/appname/v2/heartbeat?"
6802016/11/15 19:12:25 [debug] 30743#30743: *162 pipe write downstream done
6812016/11/15 19:12:25 [debug] 30743#30743: *162 event timer: 7, old: 1479237205593, new: 1479237205605
6822016/11/15 19:12:25 [debug] 30743#30743: *162 http upstream exit: 0000000000000000
6832016/11/15 19:12:25 [debug] 30743#30743: *162 finalize http upstream request: 0
6842016/11/15 19:12:25 [debug] 30743#30743: *162 finalize http proxy request
6852016/11/15 19:12:25 [debug] 30743#30743: *162 free rr peer 1 0
6862016/11/15 19:12:25 [debug] 30743#30743: *162 close http upstream connection: 7
6872016/11/15 19:12:25 [debug] 30743#30743: *162 free: 00000F0D34DBBA30, unused: 48
6882016/11/15 19:12:25 [debug] 30743#30743: *162 event timer del: 7: 1479237205593
6892016/11/15 19:12:25 [debug] 30743#30743: *162 reusable connection: 0
6902016/11/15 19:12:25 [debug] 30743#30743: *162 http upstream temp fd: -1
6912016/11/15 19:12:25 [debug] 30743#30743: *162 http output filter "/appname/v2/heartbeat?"
6922016/11/15 19:12:25 [debug] 30743#30743: *162 http copy filter: "/appname/v2/heartbeat?"
6932016/11/15 19:12:25 [debug] 30743#30743: *162 lua capture body filter, uri "/appname/v2/heartbeat"
6942016/11/15 19:12:25 [debug] 30743#30743: *162 http postpone filter "/appname/v2/heartbeat?" 00007A9E70E05A50
6952016/11/15 19:12:25 [debug] 30743#30743: *162 write old buf t:1 f:0 00000F0D34D69D00, pos 00000F0D34D69DD8, size: 840 file: 0, size: 0
6962016/11/15 19:12:25 [debug] 30743#30743: *162 write new buf t:0 f:0 0000000000000000, pos 0000000000000000, size: 0 file: 0, size: 0
6972016/11/15 19:12:25 [debug] 30743#30743: *162 http write filter: l:1 f:0 s:840
6982016/11/15 19:12:25 [debug] 30743#30743: *162 http write filter limit 0
6992016/11/15 19:12:25 [debug] 30743#30743: *162 http2:445 create DATA frame 00000F0D34DBEDA8: len:840 flags:1
7002016/11/15 19:12:25 [debug] 30743#30743: *162 http2 frame out: 00000F0D34DBEDA8 sid:445 bl:0 len:840
7012016/11/15 19:12:25 [debug] 30743#30743: *162 SSL buf copy: 9
7022016/11/15 19:12:25 [debug] 30743#30743: *162 SSL buf copy: 840
7032016/11/15 19:12:25 [debug] 30743#30743: *162 SSL to write: 956
7042016/11/15 19:12:25 [debug] 30743#30743: *162 SSL_write: 956
7052016/11/15 19:12:25 [debug] 30743#30743: *162 http2:445 DATA frame 00000F0D34DBEDA8 was sent
7062016/11/15 19:12:25 [debug] 30743#30743: *162 http2 frame sent: 00000F0D34DBEDA8 sid:445 bl:0 len:840
7072016/11/15 19:12:25 [debug] 30743#30743: *162 http write filter 0000000000000000
7082016/11/15 19:12:25 [debug] 30743#30743: *162 http copy filter: 0 "/appname/v2/heartbeat?"
7092016/11/15 19:12:25 [debug] 30743#30743: *162 http finalize request: 0, "/appname/v2/heartbeat?" a:1, c:1
7102016/11/15 19:12:25 [debug] 30743#30743: *162 http request count:1 blk:0
7112016/11/15 19:12:25 [debug] 30743#30743: *162 http2 close stream 445, queued 0, processing 1
7122016/11/15 19:12:25 [debug] 30743#30743: *162 http close request
7132016/11/15 19:12:25 [debug] 30743#30743: *162 http log handler
7142016/11/15 19:12:25 [debug] 30743#30743: *162 free: 00000F0D34DBC950
7152016/11/15 19:12:25 [debug] 30743#30743: *162 free: 00000F0D34D69D00
7162016/11/15 19:12:25 [debug] 30743#30743: *162 free: 00000F0D34E03BC0, unused: 0
7172016/11/15 19:12:25 [debug] 30743#30743: *162 free: 00000F0D34E63480, unused: 2
7182016/11/15 19:12:25 [debug] 30743#30743: *162 free: 00000F0D34EB6570, unused: 0
7192016/11/15 19:12:25 [debug] 30743#30743: *162 free: 00000F0D34EB7580, unused: 8
7202016/11/15 19:12:25 [debug] 30743#30743: *162 free: 00000F0D34DBD960, unused: 0
7212016/11/15 19:12:25 [debug] 30743#30743: *162 free: 00000F0D34DBE970, unused: 1926
7222016/11/15 19:12:25 [debug] 30743#30743: *162 free: 00000F0D34E61530, unused: 162
7232016/11/15 19:12:25 [debug] 30743#30743: *162 free: 00000F0D34E16F00, unused: 156
7242016/11/15 19:12:25 [debug] 30743#30743: *162 free: 00000F0D34DC4930, unused: 111
7252016/11/15 19:12:25 [debug] 30743#30743: *162 post event 00006EFC4C5081F0
7262016/11/15 19:12:25 [debug] 30743#30743: *162 delete posted event 00006EFC4C5081F0
7272016/11/15 19:12:25 [debug] 30743#30743: *162 http2 handle connection handler
7282016/11/15 19:12:25 [debug] 30743#30743: *162 free: 00000F0D34E120F0, unused: 3488
7292016/11/15 19:12:25 [debug] 30743#30743: *162 free: 00000F0D34D83A10
7302016/11/15 19:12:25 [debug] 30743#30743: *162 reusable connection: 1
7312016/11/15 19:12:25 [debug] 30743#30743: *162 event timer add: 3: 180000:1479237325605
7322016/11/15 19:12:29 [debug] 30743#30743: *162 http2 idle handler
7332016/11/15 19:12:29 [debug] 30743#30743: *162 reusable connection: 0
7342016/11/15 19:12:29 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E03BC0:4096 @16
7352016/11/15 19:12:29 [debug] 30743#30743: *162 http2 read handler
7362016/11/15 19:12:29 [debug] 30743#30743: *162 SSL_read: 55
7372016/11/15 19:12:29 [debug] 30743#30743: *162 SSL_read: 2861
7382016/11/15 19:12:29 [debug] 30743#30743: *162 SSL_read: 2861
7392016/11/15 19:12:29 [debug] 30743#30743: *162 SSL_read: 2861
7402016/11/15 19:12:29 [debug] 30743#30743: *162 SSL_read: 2861
7412016/11/15 19:12:29 [debug] 30743#30743: *162 SSL_read: -1
7422016/11/15 19:12:29 [debug] 30743#30743: *162 SSL_get_error: 2
7432016/11/15 19:12:29 [debug] 30743#30743: *162 process http2 frame type:1 f:24 l:46 sid:447
7442016/11/15 19:12:29 [debug] 30743#30743: *162 http2 HEADERS frame sid:447 on 0 excl:0 weight:183
7452016/11/15 19:12:29 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DC4930:1024 @16
7462016/11/15 19:12:29 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E120F0:4096 @16
7472016/11/15 19:12:29 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E63480:4096 @16
7482016/11/15 19:12:29 [debug] 30743#30743: *162 http2 get indexed header name: 3
7492016/11/15 19:12:29 [debug] 30743#30743: *162 http2 get indexed header name: 82
7502016/11/15 19:12:29 [debug] 30743#30743: *162 http2 get indexed header name: 7
7512016/11/15 19:12:29 [debug] 30743#30743: *162 http2 hpack encoded string length: 4
7522016/11/15 19:12:29 [debug] 30743#30743: *162 http2 hpack encoded string length: 13
7532016/11/15 19:12:29 [debug] 30743#30743: *162 http uri: "/appname/v2/heartbeat"
7542016/11/15 19:12:29 [debug] 30743#30743: *162 http args: ""
7552016/11/15 19:12:29 [debug] 30743#30743: *162 http exten: ""
7562016/11/15 19:12:29 [debug] 30743#30743: *162 http2 get indexed header: 28
7572016/11/15 19:12:29 [debug] 30743#30743: *162 http2 hpack encoded string length: 4
7582016/11/15 19:12:29 [debug] 30743#30743: *162 http2 add header to hpack table: "content-length: 27408"
7592016/11/15 19:12:29 [debug] 30743#30743: *162 http2 hpack table account: 51 free:37
7602016/11/15 19:12:29 [debug] 30743#30743: *162 http2 http header: "content-length: 27408"
7612016/11/15 19:12:29 [debug] 30743#30743: *162 http2 get indexed header name: 81
7622016/11/15 19:12:29 [debug] 30743#30743: *162 http2 http header: "accept: application/json, text/plain, */*"
7632016/11/15 19:12:29 [debug] 30743#30743: *162 http2 get indexed header name: 93
7642016/11/15 19:12:29 [debug] 30743#30743: *162 http2 http header: "origin: https://app3.mydomain.local"
7652016/11/15 19:12:29 [debug] 30743#30743: *162 http2 get indexed header name: 71
7662016/11/15 19:12:29 [debug] 30743#30743: *162 http2 http header: "appname-csrf-token: YYY
7672016/11/15 19:12:29 [debug] 30743#30743: *162 http2 get indexed header name: 77
7682016/11/15 19:12:29 [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"
7692016/11/15 19:12:29 [debug] 30743#30743: *162 http2 get indexed header name: 92
7702016/11/15 19:12:29 [debug] 30743#30743: *162 http2 http header: "content-type: application/json;charset=UTF-8"
7712016/11/15 19:12:29 [debug] 30743#30743: *162 http2 get indexed header name: 90
7722016/11/15 19:12:29 [debug] 30743#30743: *162 http2 http header: "accept-encoding: gzip, deflate, br"
7732016/11/15 19:12:29 [debug] 30743#30743: *162 http2 get indexed header name: 68
7742016/11/15 19:12:29 [debug] 30743#30743: *162 http2 http header: "accept-language: en-US,en;q=0.8"
7752016/11/15 19:12:29 [debug] 30743#30743: *162 http2 get indexed header name: 67
7762016/11/15 19:12:29 [debug] 30743#30743: *162 http2 get indexed header name: 66
7772016/11/15 19:12:29 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E16F00:1024 @16
7782016/11/15 19:12:29 [debug] 30743#30743: *162 http2 get indexed header name: 65
7792016/11/15 19:12:29 [debug] 30743#30743: *162 posix_memalign: 00000F0D34E61530:1024 @16
7802016/11/15 19:12:29 [debug] 30743#30743: *162 http2 get indexed header name: 64
7812016/11/15 19:12:29 [debug] 30743#30743: *162 http2 get indexed header name: 70
7822016/11/15 19:12:29 [debug] 30743#30743: *162 http2 http request line: "POST /appname/v2/heartbeat HTTP/2.0"
7832016/11/15 19:12:29 [debug] 30743#30743: *162 generic phase: 0
7842016/11/15 19:12:29 [debug] 30743#30743: *162 rewrite phase: 1
7852016/11/15 19:12:29 [debug] 30743#30743: *162 test location: "^/widgets/$"
7862016/11/15 19:12:29 [debug] 30743#30743: *162 test location: "/"
7872016/11/15 19:12:29 [debug] 30743#30743: *162 test location: "docs/"
7882016/11/15 19:12:29 [debug] 30743#30743: *162 test location: "appname/socket"
7892016/11/15 19:12:29 [debug] 30743#30743: *162 test location: ~ "^/(index.html)?$"
7902016/11/15 19:12:29 [debug] 30743#30743: *162 test location: ~ "^/login/?$"
7912016/11/15 19:12:29 [debug] 30743#30743: *162 test location: ~ "^/(appname)"
7922016/11/15 19:12:29 [debug] 30743#30743: *162 test location: ~ "/components/(.*)"
7932016/11/15 19:12:29 [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)$"
7942016/11/15 19:12:29 [debug] 30743#30743: *162 using configuration "/"
7952016/11/15 19:12:29 [debug] 30743#30743: *162 http cl:27408 max:1073741824
7962016/11/15 19:12:29 [debug] 30743#30743: *162 rewrite phase: 3
7972016/11/15 19:12:29 [debug] 30743#30743: *162 post rewrite phase: 4
7982016/11/15 19:12:29 [debug] 30743#30743: *162 generic phase: 5
7992016/11/15 19:12:29 [debug] 30743#30743: *162 generic phase: 6
8002016/11/15 19:12:29 [debug] 30743#30743: *162 generic phase: 7
8012016/11/15 19:12:29 [debug] 30743#30743: *162 access phase: 8
8022016/11/15 19:12:29 [debug] 30743#30743: *162 access phase: 9
8032016/11/15 19:12:29 [debug] 30743#30743: *162 access phase: 10
8042016/11/15 19:12:29 [debug] 30743#30743: *162 auth request handler
8052016/11/15 19:12:29 [debug] 30743#30743: *162 posix_memalign: 00000F0D34EB6570:4096 @16
8062016/11/15 19:12:29 [debug] 30743#30743: *162 http subrequest "/authorize?"
8072016/11/15 19:12:29 [debug] 30743#30743: *162 http posted request: "/authorize?"
8082016/11/15 19:12:29 [debug] 30743#30743: *162 rewrite phase: 1
8092016/11/15 19:12:29 [debug] 30743#30743: *162 test location: "^/widgets/$"
8102016/11/15 19:12:29 [debug] 30743#30743: *162 test location: "/"
8112016/11/15 19:12:29 [debug] 30743#30743: *162 test location: "docs/"
8122016/11/15 19:12:29 [debug] 30743#30743: *162 test location: "dashboard"
8132016/11/15 19:12:29 [debug] 30743#30743: *162 test location: "authorize"
8142016/11/15 19:12:29 [debug] 30743#30743: *162 using configuration "=/authorize"
8152016/11/15 19:12:29 [debug] 30743#30743: *162 http cl:27408 max:1073741824
8162016/11/15 19:12:29 [debug] 30743#30743: *162 rewrite phase: 3
8172016/11/15 19:12:29 [debug] 30743#30743: *162 post rewrite phase: 4
8182016/11/15 19:12:29 [debug] 30743#30743: *162 generic phase: 5
8192016/11/15 19:12:29 [debug] 30743#30743: *162 generic phase: 6
8202016/11/15 19:12:29 [debug] 30743#30743: *162 generic phase: 7
8212016/11/15 19:12:29 [debug] 30743#30743: *162 http init upstream, client timer: 0
8222016/11/15 19:12:29 [debug] 30743#30743: *162 posix_memalign: 00000F0D34EB7580:4096 @16
8232016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: "X-Real-IP: "
8242016/11/15 19:12:29 [debug] 30743#30743: *162 http script var: "192.168.123.11"
8252016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: "
826"
8272016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: "X-Forwarded-For: "
8282016/11/15 19:12:29 [debug] 30743#30743: *162 http script var: "192.168.123.11"
8292016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: "
830"
8312016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: "Host: "
8322016/11/15 19:12:29 [debug] 30743#30743: *162 http script var: "app3.mydomain.local"
8332016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: "
834"
8352016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: "X-NginX-Proxy: true
836"
8372016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: "X-Client-S-DN: "
8382016/11/15 19:12:29 [debug] 30743#30743: *162 http script var: "XXX"
8392016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: "
840"
8412016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: "X-Client-Serial: "
8422016/11/15 19:12:29 [debug] 30743#30743: *162 http script var: "XXXX"
8432016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: "
844"
8452016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: "x-appname-uri: "
8462016/11/15 19:12:29 [debug] 30743#30743: *162 http script var: "/appname/v2/heartbeat"
8472016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: "
848"
8492016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: "x-appname-method: "
8502016/11/15 19:12:29 [debug] 30743#30743: *162 http script var: "POST"
8512016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: "
852"
8532016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: "Connection: close
854"
8552016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: ""
8562016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: ""
8572016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy header: "accept: application/json, text/plain, */*"
8582016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy header: "origin: https://app3.mydomain.local"
8592016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy header: "appname-csrf-token: YYY
8602016/11/15 19:12:29 [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"
8612016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy header: "content-type: application/json;charset=UTF-8"
8622016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy header: "accept-encoding: gzip, deflate, br"
8632016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy header: "accept-language: en-US,en;q=0.8"
8642016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy header: "cookie: XXX"
8652016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy header:
866"GET /authorize HTTP/1.1
867X-Real-IP: 192.168.123.11
868X-Forwarded-For: 192.168.123.11
869Host: app3.mydomain.local
870X-NginX-Proxy: true
871
872
873x-appname-uri: /appname/v2/heartbeat
874x-appname-method: POST
875Connection: close
876accept: application/json, text/plain, */*
877origin: https://app3.mydomain.local
878appname-csrf-token: YYY
879user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.75 Safari/537.36
880content-type: application/json;charset=UTF-8
881accept-encoding: gzip, deflate, br
882accept-language: en-US,en;q=0.8
8832016/11/15 19:12:29 [debug] 30743#30743: *162 http cleanup add: 00000F0D34E64460
8842016/11/15 19:12:29 [debug] 30743#30743: *162 get rr peer, try: 1
8852016/11/15 19:12:29 [debug] 30743#30743: *162 stream socket 7
8862016/11/15 19:12:29 [debug] 30743#30743: *162 epoll add connection: fd:7 ev:80002005
8872016/11/15 19:12:29 [debug] 30743#30743: *162 connect to 127.0.0.1:8008, fd:7 #589
8882016/11/15 19:12:29 [debug] 30743#30743: *162 http upstream connect: -2
8892016/11/15 19:12:29 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBBA30:128 @16
8902016/11/15 19:12:29 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237209569
8912016/11/15 19:12:29 [debug] 30743#30743: *162 http finalize request: -4, "/authorize?" a:1, c:3
8922016/11/15 19:12:29 [debug] 30743#30743: *162 http request count:3 blk:0
8932016/11/15 19:12:29 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AC047 end:00006EFC4F5AECFB
8942016/11/15 19:12:29 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:447
8952016/11/15 19:12:29 [debug] 30743#30743: *162 http2 DATA frame
8962016/11/15 19:12:29 [debug] 30743#30743: *162 malloc: 00000F0D34D89720:65536
8972016/11/15 19:12:29 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5ACB74 end:00006EFC4F5AECFB
8982016/11/15 19:12:29 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:447
8992016/11/15 19:12:29 [debug] 30743#30743: *162 http2 DATA frame
9002016/11/15 19:12:29 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AD6A1 end:00006EFC4F5AECFB
9012016/11/15 19:12:29 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:447
9022016/11/15 19:12:29 [debug] 30743#30743: *162 http2 DATA frame
9032016/11/15 19:12:29 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AE1CE end:00006EFC4F5AECFB
9042016/11/15 19:12:29 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:447
9052016/11/15 19:12:29 [debug] 30743#30743: *162 http2 DATA frame
9062016/11/15 19:12:29 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AECFB end:00006EFC4F5AECFB
9072016/11/15 19:12:29 [debug] 30743#30743: *162 event timer del: 3: 1479237325605
9082016/11/15 19:12:29 [debug] 30743#30743: *162 http2 write handler
9092016/11/15 19:12:29 [debug] 30743#30743: *162 http2 read handler
9102016/11/15 19:12:29 [debug] 30743#30743: *162 SSL_read: 2861
9112016/11/15 19:12:29 [debug] 30743#30743: *162 SSL_read: 2861
9122016/11/15 19:12:29 [debug] 30743#30743: *162 SSL_read: 2861
9132016/11/15 19:12:29 [debug] 30743#30743: *162 SSL_read: 2861
9142016/11/15 19:12:29 [debug] 30743#30743: *162 SSL_read: 2861
9152016/11/15 19:12:29 [debug] 30743#30743: *162 SSL_read: 1749
9162016/11/15 19:12:29 [debug] 30743#30743: *162 SSL_read: -1
9172016/11/15 19:12:29 [debug] 30743#30743: *162 SSL_get_error: 2
9182016/11/15 19:12:29 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:447
9192016/11/15 19:12:29 [debug] 30743#30743: *162 http2 DATA frame
9202016/11/15 19:12:29 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5ACB3D end:00006EFC4F5AFEC6
9212016/11/15 19:12:29 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:447
9222016/11/15 19:12:29 [debug] 30743#30743: *162 http2 DATA frame
9232016/11/15 19:12:29 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AD66A end:00006EFC4F5AFEC6
9242016/11/15 19:12:29 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:447
9252016/11/15 19:12:29 [debug] 30743#30743: *162 http2 DATA frame
9262016/11/15 19:12:29 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AE197 end:00006EFC4F5AFEC6
9272016/11/15 19:12:29 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:447
9282016/11/15 19:12:29 [debug] 30743#30743: *162 http2 DATA frame
9292016/11/15 19:12:29 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AECC4 end:00006EFC4F5AFEC6
9302016/11/15 19:12:29 [debug] 30743#30743: *162 process http2 frame type:0 f:0 l:2852 sid:447
9312016/11/15 19:12:29 [debug] 30743#30743: *162 http2 DATA frame
9322016/11/15 19:12:29 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AF7F1 end:00006EFC4F5AFEC6
9332016/11/15 19:12:29 [debug] 30743#30743: *162 process http2 frame type:0 f:1 l:1740 sid:447
9342016/11/15 19:12:29 [debug] 30743#30743: *162 http2 DATA frame
9352016/11/15 19:12:29 [debug] 30743#30743: *162 http2 frame complete pos:00006EFC4F5AFEC6 end:00006EFC4F5AFEC6
9362016/11/15 19:12:29 [debug] 30743#30743: *162 http2 write handler
9372016/11/15 19:12:29 [debug] 30743#30743: *162 http upstream request: "/authorize?"
9382016/11/15 19:12:29 [debug] 30743#30743: *162 http upstream send request handler
9392016/11/15 19:12:29 [debug] 30743#30743: *162 http upstream send request
9402016/11/15 19:12:29 [debug] 30743#30743: *162 http upstream send request body
9412016/11/15 19:12:29 [debug] 30743#30743: *162 chain writer buf fl:1 s:2711
9422016/11/15 19:12:29 [debug] 30743#30743: *162 chain writer in: 00000F0D34EB7550
9432016/11/15 19:12:29 [debug] 30743#30743: *162 writev: 2711 of 2711
9442016/11/15 19:12:29 [debug] 30743#30743: *162 chain writer out: 0000000000000000
9452016/11/15 19:12:29 [debug] 30743#30743: *162 event timer del: 7: 1479237209569
9462016/11/15 19:12:29 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237209570
9472016/11/15 19:12:29 [debug] 30743#30743: *162 http upstream request: "/authorize?"
9482016/11/15 19:12:29 [debug] 30743#30743: *162 http upstream process header
9492016/11/15 19:12:29 [debug] 30743#30743: *162 malloc: 00000F0D34DBC950:4096
9502016/11/15 19:12:29 [debug] 30743#30743: *162 recv: fd:7 172 of 4096
9512016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy status 200 "200 OK"
9522016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy header: "X-Powered-By: Express"
9532016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy header: "x-appname-origin: appname3"
9542016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy header: "content-type: application/json"
9552016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy header: "content-length: 0"
9562016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy header: "Date: Tue, 15 Nov 2016 19:12:29 GMT"
9572016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy header: "Connection: close"
9582016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy header done
9592016/11/15 19:12:29 [debug] 30743#30743: *162 lua capture header filter, uri "/authorize"
9602016/11/15 19:12:29 [debug] 30743#30743: *162 http2 header filter
9612016/11/15 19:12:29 [debug] 30743#30743: *162 finalize http upstream request: 0
9622016/11/15 19:12:29 [debug] 30743#30743: *162 finalize http proxy request
9632016/11/15 19:12:29 [debug] 30743#30743: *162 free rr peer 1 0
9642016/11/15 19:12:29 [debug] 30743#30743: *162 close http upstream connection: 7
9652016/11/15 19:12:29 [debug] 30743#30743: *162 free: 00000F0D34DBBA30, unused: 48
9662016/11/15 19:12:29 [debug] 30743#30743: *162 event timer del: 7: 1479237209570
9672016/11/15 19:12:29 [debug] 30743#30743: *162 reusable connection: 0
9682016/11/15 19:12:29 [debug] 30743#30743: *162 http finalize request: 0, "/authorize?" a:1, c:2
9692016/11/15 19:12:29 [debug] 30743#30743: *162 auth request done s:200
9702016/11/15 19:12:29 [debug] 30743#30743: *162 http wake parent request: "/appname/v2/heartbeat?"
9712016/11/15 19:12:29 [debug] 30743#30743: *162 http posted request: "/appname/v2/heartbeat?"
9722016/11/15 19:12:29 [debug] 30743#30743: *162 access phase: 10
9732016/11/15 19:12:29 [debug] 30743#30743: *162 auth request handler
9742016/11/15 19:12:29 [debug] 30743#30743: *162 auth request set variables
9752016/11/15 19:12:29 [debug] 30743#30743: *162 access phase: 11
9762016/11/15 19:12:29 [debug] 30743#30743: *162 lua access handler, uri:"/appname/v2/heartbeat" c:1
9772016/11/15 19:12:29 [debug] 30743#30743: *162 post access phase: 12
9782016/11/15 19:12:29 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBD960:4096 @16
9792016/11/15 19:12:29 [debug] 30743#30743: *162 http body new buf t:1 f:0 00000F0D34D89720, pos 00000F0D34D89720, size: 27408 file: 0, size: 0
9802016/11/15 19:12:29 [debug] 30743#30743: *162 http init upstream, client timer: 0
9812016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: "X-Real-IP: "
9822016/11/15 19:12:29 [debug] 30743#30743: *162 http script var: "192.168.123.11"
9832016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: "
984"
9852016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: "X-Forwarded-For: "
9862016/11/15 19:12:29 [debug] 30743#30743: *162 http script var: "192.168.123.11"
9872016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: "
988"
9892016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: "Host: "
9902016/11/15 19:12:29 [debug] 30743#30743: *162 http script var: "app3.mydomain.local"
9912016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: "
992"
9932016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: "X-NginX-Proxy: true
994"
9952016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: "X-Client-S-DN: "
9962016/11/15 19:12:29 [debug] 30743#30743: *162 http script var: "XXX"
9972016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: "
998"
9992016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: "X-Client-Serial: "
10002016/11/15 19:12:29 [debug] 30743#30743: *162 http script var: "XXXX"
10012016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: "
1002"
10032016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: "Connection: close
1004"
10052016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: "Content-Length: "
10062016/11/15 19:12:29 [debug] 30743#30743: *162 http script var: "27408"
10072016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: "
1008"
10092016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: ""
10102016/11/15 19:12:29 [debug] 30743#30743: *162 http script copy: ""
10112016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy header: "accept: application/json, text/plain, */*"
10122016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy header: "origin: https://app3.mydomain.local"
10132016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy header: "appname-csrf-token: YYY
10142016/11/15 19:12:29 [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"
10152016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy header: "content-type: application/json;charset=UTF-8"
10162016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy header: "accept-encoding: gzip, deflate, br"
10172016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy header: "accept-language: en-US,en;q=0.8"
10182016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy header: "cookie: XXX"
10192016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy header:
1020"POST /appname/v2/heartbeat HTTP/1.1
1021X-Real-IP: 192.168.123.11
1022X-Forwarded-For: 192.168.123.11
1023Host: app3.mydomain.local
1024X-NginX-Proxy: true
1025
1026
1027Connection: close
1028Content-Length: 27408
1029accept: application/json, text/plain, */*
1030origin: https://app3.mydomain.local
1031appname-csrf-token: YYY
1032user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.75 Safari/537.36
1033content-type: application/json;charset=UTF-8
1034accept-encoding: gzip, deflate, br
1035accept-language: en-US,en;q=0.8
10362016/11/15 19:12:29 [debug] 30743#30743: *162 http cleanup add: 00000F0D34DBE938
10372016/11/15 19:12:29 [debug] 30743#30743: *162 get rr peer, try: 1
10382016/11/15 19:12:29 [debug] 30743#30743: *162 stream socket 7
10392016/11/15 19:12:29 [debug] 30743#30743: *162 epoll add connection: fd:7 ev:80002005
10402016/11/15 19:12:29 [debug] 30743#30743: *162 connect to 182.168.128.69:8080, fd:7 #590
10412016/11/15 19:12:29 [debug] 30743#30743: *162 http upstream connect: -2
10422016/11/15 19:12:29 [debug] 30743#30743: *162 posix_memalign: 00000F0D34DBBA30:128 @16
10432016/11/15 19:12:29 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237209593
10442016/11/15 19:12:29 [debug] 30743#30743: *162 free: 00000F0D34D89720
10452016/11/15 19:12:29 [debug] 30743#30743: *162 http finalize request: -4, "/appname/v2/heartbeat?" a:1, c:2
10462016/11/15 19:12:29 [debug] 30743#30743: *162 http request count:2 blk:0
10472016/11/15 19:12:29 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?"
10482016/11/15 19:12:29 [debug] 30743#30743: *162 http upstream send request handler
10492016/11/15 19:12:29 [debug] 30743#30743: *162 http upstream send request
10502016/11/15 19:12:29 [debug] 30743#30743: *162 http upstream send request body
10512016/11/15 19:12:29 [debug] 30743#30743: *162 chain writer buf fl:0 s:2690
10522016/11/15 19:12:29 [debug] 30743#30743: *162 chain writer buf fl:1 s:27408
10532016/11/15 19:12:29 [debug] 30743#30743: *162 chain writer in: 00000F0D34DBEA00
10542016/11/15 19:12:29 [debug] 30743#30743: *162 writev: 28960 of 30098
10552016/11/15 19:12:29 [debug] 30743#30743: *162 chain writer out: 00000F0D34DBEA10
10562016/11/15 19:12:29 [debug] 30743#30743: *162 event timer: 7, old: 1479237209593, new: 1479237209593
10572016/11/15 19:12:29 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?"
10582016/11/15 19:12:29 [debug] 30743#30743: *162 http upstream send request handler
10592016/11/15 19:12:29 [debug] 30743#30743: *162 http upstream send request
10602016/11/15 19:12:29 [debug] 30743#30743: *162 http upstream send request body
10612016/11/15 19:12:29 [debug] 30743#30743: *162 chain writer in: 00000F0D34DBEA10
10622016/11/15 19:12:29 [debug] 30743#30743: *162 writev: 1138 of 1138
10632016/11/15 19:12:29 [debug] 30743#30743: *162 chain writer out: 0000000000000000
10642016/11/15 19:12:29 [debug] 30743#30743: *162 event timer del: 7: 1479237209593
10652016/11/15 19:12:29 [debug] 30743#30743: *162 event timer add: 7: 60000:1479237209594
10662016/11/15 19:12:29 [debug] 30743#30743: *162 http upstream request: "/appname/v2/heartbeat?"
10672016/11/15 19:12:29 [debug] 30743#30743: *162 http upstream process header
10682016/11/15 19:12:29 [debug] 30743#30743: *162 malloc: 00000F0D34D69D00:4096
10692016/11/15 19:12:29 [debug] 30743#30743: *162 recv: fd:7 1056 of 4096
10702016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy status 400 "400 Bad Request"
10712016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy header: "Server: nginx"
10722016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy header: "Date: Tue, 15 Nov 2016 19:12:30 GMT"
10732016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy header: "Content-Type: text/html; charset=utf-8"
10742016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy header: "Content-Length: 840"
10752016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy header: "Connection: close"
10762016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy header: "X-Powered-By: Express"
10772016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy header: "X-Content-Type-Options: nosniff"
10782016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy header done
10792016/11/15 19:12:29 [debug] 30743#30743: *162 lua capture header filter, uri "/appname/v2/heartbeat"
10802016/11/15 19:12:29 [debug] 30743#30743: *162 http2 header filter
10812016/11/15 19:12:29 [debug] 30743#30743: *162 http2 output header: ":status: 400"
10822016/11/15 19:12:29 [debug] 30743#30743: *162 http2 output header: "server: nginx"
10832016/11/15 19:12:29 [debug] 30743#30743: *162 http2 output header: "date: Tue, 15 Nov 2016 19:12:29 GMT"
10842016/11/15 19:12:29 [debug] 30743#30743: *162 http2 output header: "content-type: text/html; charset=utf-8"
10852016/11/15 19:12:29 [debug] 30743#30743: *162 http2 output header: "content-length: 840"
10862016/11/15 19:12:29 [debug] 30743#30743: *162 http2 output header: "x-powered-by: Express"
10872016/11/15 19:12:29 [debug] 30743#30743: *162 http2 output header: "x-content-type-options: nosniff"
10882016/11/15 19:12:29 [debug] 30743#30743: *162 http2:447 create HEADERS frame 00000F0D34DBEDA8: len:98
10892016/11/15 19:12:29 [debug] 30743#30743: *162 http cleanup add: 00000F0D34DBEE90
10902016/11/15 19:12:29 [debug] 30743#30743: *162 http2 frame out: 00000F0D34DBEDA8 sid:447 bl:1 len:98
10912016/11/15 19:12:29 [debug] 30743#30743: *162 malloc: 00000F0D34D83A10:16384
10922016/11/15 19:12:29 [debug] 30743#30743: *162 SSL buf copy: 9
10932016/11/15 19:12:29 [debug] 30743#30743: *162 SSL buf copy: 98
10942016/11/15 19:12:29 [debug] 30743#30743: *162 http2:447 HEADERS frame 00000F0D34DBEDA8 was sent
10952016/11/15 19:12:29 [debug] 30743#30743: *162 http2 frame sent: 00000F0D34DBEDA8 sid:447 bl:1 len:98
10962016/11/15 19:12:29 [debug] 30743#30743: *162 http cacheable: 0
10972016/11/15 19:12:29 [debug] 30743#30743: *162 http proxy filter init s:400 h:0 c:0 l:840
10982016/11/15 19:12:29 [debug] 30743#30743: *162 http upstream process upstream
10992016/11/15 19:12:29 [debug] 30743#30743: *162 pipe read upstream: 1
11002016/11/15 19:12:29 [debug] 30743#30743: *162 pipe preread: 840
11012016/11/15 19:12:29 [debug] 30743#30743: *162 readv: 1, last:3040
11022016/11/15 19:12:29 [debug] 30743#30743: *162 pipe recv chain: 0
11032016/11/15 19:12:29 [debug] 30743#30743: *162 pipe buf free s:0 t:1 f:0 00000F0D34D69D00, pos 00000F0D34D69DD8, size: 840 file: 0, size: 0
11042016/11/15 19:12:29 [debug] 30743#30743: *162 pipe length: 840
11052016/11/15 19:12:29 [debug] 30743#30743: *162 input buf #0
11062016/11/15 19:12:29 [debug] 30743#30743: *162 pipe write downstream: 1
11072016/11/15 19:12:29 [debug] 30743#30743: *162 pipe write downstream flush in
11082016/11/15 19:12:29 [debug] 30743#30743: *162 http output filter "/appname/v2/heartbeat?"
11092016/11/15 19:12:29 [debug] 30743#30743: *162 http copy filter: "/appname/v2/heartbeat?"
11102016/11/15 19:12:29 [debug] 30743#30743: *162 lua capture body filter, uri "/appname/v2/heartbeat"
11112016/11/15 19:12:29 [debug] 30743#30743: *162 http postpone filter "/appname/v2/heartbeat?" 00000F0D34DBEA00
11122016/11/15 19:12:29 [debug] 30743#30743: *162 write new buf t:1 f:0 00000F0D34D69D00, pos 00000F0D34D69DD8, size: 840 file: 0, size: 0
11132016/11/15 19:12:29 [debug] 30743#30743: *162 http write filter: l:0 f:0 s:840
11142016/11/15 19:12:29 [debug] 30743#30743: *162 http copy filter: 0 "/appname/v2/heartbeat?"
11152016/11/15 19:12:29 [debug] 30743#30743: *162 pipe write downstream done
11162016/11/15 19:12:29 [debug] 30743#30743: *162 event timer: 7, old: 1479237209594, new: 1479237209602
11172016/11/15 19:12:29 [debug] 30743#30743: *162 http upstream exit: 0000000000000000
11182016/11/15 19:12:29 [debug] 30743#30743: *162 finalize http upstream request: 0
11192016/11/15 19:12:29 [debug] 30743#30743: *162 finalize http proxy request
11202016/11/15 19:12:29 [debug] 30743#30743: *162 free rr peer 1 0
11212016/11/15 19:12:29 [debug] 30743#30743: *162 close http upstream connection: 7
11222016/11/15 19:12:29 [debug] 30743#30743: *162 free: 00000F0D34DBBA30, unused: 48
11232016/11/15 19:12:29 [debug] 30743#30743: *162 event timer del: 7: 1479237209594
11242016/11/15 19:12:29 [debug] 30743#30743: *162 reusable connection: 0
11252016/11/15 19:12:29 [debug] 30743#30743: *162 http upstream temp fd: -1
11262016/11/15 19:12:29 [debug] 30743#30743: *162 http output filter "/appname/v2/heartbeat?"
11272016/11/15 19:12:29 [debug] 30743#30743: *162 http copy filter: "/appname/v2/heartbeat?"
11282016/11/15 19:12:29 [debug] 30743#30743: *162 lua capture body filter, uri "/appname/v2/heartbeat"
11292016/11/15 19:12:29 [debug] 30743#30743: *162 http postpone filter "/appname/v2/heartbeat?" 00007A9E70E05A50
11302016/11/15 19:12:29 [debug] 30743#30743: *162 write old buf t:1 f:0 00000F0D34D69D00, pos 00000F0D34D69DD8, size: 840 file: 0, size: 0
11312016/11/15 19:12:29 [debug] 30743#30743: *162 write new buf t:0 f:0 0000000000000000, pos 0000000000000000, size: 0 file: 0, size: 0
11322016/11/15 19:12:29 [debug] 30743#30743: *162 http write filter: l:1 f:0 s:840
11332016/11/15 19:12:29 [debug] 30743#30743: *162 http write filter limit 0
11342016/11/15 19:12:29 [debug] 30743#30743: *162 http2:447 create DATA frame 00000F0D34DBEDA8: len:840 flags:1
11352016/11/15 19:12:29 [debug] 30743#30743: *162 http2 frame out: 00000F0D34DBEDA8 sid:447 bl:0 len:840
11362016/11/15 19:12:29 [debug] 30743#30743: *162 SSL buf copy: 9
11372016/11/15 19:12:29 [debug] 30743#30743: *162 SSL buf copy: 840
11382016/11/15 19:12:29 [debug] 30743#30743: *162 SSL to write: 956
11392016/11/15 19:12:29 [debug] 30743#30743: *162 SSL_write: 956
11402016/11/15 19:12:29 [debug] 30743#30743: *162 http2:447 DATA frame 00000F0D34DBEDA8 was sent
11412016/11/15 19:12:29 [debug] 30743#30743: *162 http2 frame sent: 00000F0D34DBEDA8 sid:447 bl:0 len:840
11422016/11/15 19:12:29 [debug] 30743#30743: *162 http write filter 0000000000000000
11432016/11/15 19:12:29 [debug] 30743#30743: *162 http copy filter: 0 "/appname/v2/heartbeat?"
11442016/11/15 19:12:29 [debug] 30743#30743: *162 http finalize request: 0, "/appname/v2/heartbeat?" a:1, c:1
11452016/11/15 19:12:29 [debug] 30743#30743: *162 http request count:1 blk:0
11462016/11/15 19:12:29 [debug] 30743#30743: *162 http2 close stream 447, queued 0, processing 1
11472016/11/15 19:12:29 [debug] 30743#30743: *162 http close request
11482016/11/15 19:12:29 [debug] 30743#30743: *162 http log handler
11492016/11/15 19:12:29 [debug] 30743#30743: *162 free: 00000F0D34DBC950
11502016/11/15 19:12:29 [debug] 30743#30743: *162 free: 00000F0D34D69D00
11512016/11/15 19:12:29 [debug] 30743#30743: *162 free: 00000F0D34E120F0, unused: 0
11522016/11/15 19:12:29 [debug] 30743#30743: *162 free: 00000F0D34E63480, unused: 2
11532016/11/15 19:12:29 [debug] 30743#30743: *162 free: 00000F0D34EB6570, unused: 0
11542016/11/15 19:12:29 [debug] 30743#30743: *162 free: 00000F0D34EB7580, unused: 8
11552016/11/15 19:12:29 [debug] 30743#30743: *162 free: 00000F0D34DBD960, unused: 0
11562016/11/15 19:12:29 [debug] 30743#30743: *162 free: 00000F0D34DBE970, unused: 1926
11572016/11/15 19:12:29 [debug] 30743#30743: *162 free: 00000F0D34DC4930, unused: 162
11582016/11/15 19:12:29 [debug] 30743#30743: *162 free: 00000F0D34E16F00, unused: 156
11592016/11/15 19:12:29 [debug] 30743#30743: *162 free: 00000F0D34E61530, unused: 111
11602016/11/15 19:12:29 [debug] 30743#30743: *162 post event 00006EFC4C5081F0
11612016/11/15 19:12:29 [debug] 30743#30743: *162 delete posted event 00006EFC4C5081F0
11622016/11/15 19:12:29 [debug] 30743#30743: *162 http2 handle connection handler
11632016/11/15 19:12:29 [debug] 30743#30743: *162 free: 00000F0D34E03BC0, unused: 3488
11642016/11/15 19:12:29 [debug] 30743#30743: *162 free: 00000F0D34D83A10
11652016/11/15 19:12:29 [debug] 30743#30743: *162 reusable connection: 1
11662016/11/15 19:12:29 [debug] 30743#30743: *162 event timer add: 3: 180000:1479237329602