2017/01/14 02:46:58 [debug] 14576#0: *358792 accept: X.X.X.X:51644 fd:117 2017/01/14 02:46:58 [debug] 14576#0: *358792 event timer add: 117: 60000:1484362078365 2017/01/14 02:46:58 [debug] 14576#0: *358792 reusable connection: 1 2017/01/14 02:46:58 [debug] 14576#0: *358792 epoll add event: fd:117 op:1 ev:80002001 2017/01/14 02:46:58 [debug] 14576#0: *358792 post event 00007F2ECE033C10 2017/01/14 02:46:58 [debug] 14576#0: *358792 delete posted event 00007F2ECE033C10 2017/01/14 02:46:58 [debug] 14576#0: *358792 http check ssl handshake 2017/01/14 02:46:58 [debug] 14576#0: *358792 http recv(): 1 2017/01/14 02:46:58 [debug] 14576#0: *358792 https ssl handshake: 0x16 2017/01/14 02:46:58 [debug] 14576#0: *358792 SSL server name: "A.B.C" 2017/01/14 02:46:58 [debug] 14576#0: *358792 SSL_do_handshake: -1 2017/01/14 02:46:58 [debug] 14576#0: *358792 SSL_get_error: 2 2017/01/14 02:46:58 [debug] 14576#0: *358792 reusable connection: 0 2017/01/14 02:46:58 [debug] 14576#0: *358792 SSL handshake handler: 0 2017/01/14 02:46:58 [debug] 14576#0: *358792 SSL_do_handshake: -1 2017/01/14 02:46:58 [debug] 14576#0: *358792 SSL_get_error: 2 2017/01/14 02:46:58 [debug] 14576#0: *358792 post event 00007F2ECE033C10 2017/01/14 02:46:58 [debug] 14576#0: *358792 delete posted event 00007F2ECE033C10 2017/01/14 02:46:58 [debug] 14576#0: *358792 SSL handshake handler: 0 2017/01/14 02:46:58 [debug] 14576#0: *358792 SSL_do_handshake: 1 2017/01/14 02:46:58 [debug] 14576#0: *358792 SSL: TLSv1, cipher: “cipher1” 2017/01/14 02:46:58 [debug] 14576#0: *358792 reusable connection: 1 2017/01/14 02:46:58 [debug] 14576#0: *358792 http wait request handler 2017/01/14 02:46:58 [debug] 14576#0: *358792 malloc: 0000000004EC3890:1024 2017/01/14 02:46:58 [debug] 14576#0: *358792 SSL_read: -1 2017/01/14 02:46:58 [debug] 14576#0: *358792 SSL_get_error: 2 2017/01/14 02:46:58 [debug] 14576#0: *358792 free: 0000000004EC3890 2017/01/14 02:46:59 [debug] 14576#0: *358792 http wait request handler 2017/01/14 02:46:59 [debug] 14576#0: *358792 malloc: 00000000050FFC60:1024 2017/01/14 02:46:59 [debug] 14576#0: *358792 SSL_read: 455 2017/01/14 02:46:59 [debug] 14576#0: *358792 SSL_read: 0 2017/01/14 02:46:59 [debug] 14576#0: *358792 SSL_get_error: 6 2017/01/14 02:46:59 [debug] 14576#0: *358792 peer shutdown SSL cleanly 2017/01/14 02:46:59 [debug] 14576#0: *358792 reusable connection: 0 2017/01/14 02:46:59 [debug] 14576#0: *358792 posix_memalign: 00000000050F7CE0:4096 @16 2017/01/14 02:46:59 [debug] 14576#0: *358792 http process request line 2017/01/14 02:46:59 [debug] 14576#0: *358792 http request line: "POST /X/Y/Z?k1=v1&k2=v2 HTTP/1.1" 2017/01/14 02:46:59 [debug] 14576#0: *358792 http uri: “X/Y/Z” 2017/01/14 02:46:59 [debug] 14576#0: *358792 http args: "k1=v1&k2=v2" 2017/01/14 02:46:59 [debug] 14576#0: *358792 http exten: "" 2017/01/14 02:46:59 [debug] 14576#0: *358792 posix_memalign: 0000000003F42E70:4096 @16 2017/01/14 02:46:59 [debug] 14576#0: *358792 http process request header line 2017/01/14 02:46:59 [debug] 14576#0: *358792 http header: "Content-Type: application/octet-stream" 2017/01/14 02:46:59 [debug] 14576#0: *358792 http header: "content-encoding: gzip" 2017/01/14 02:46:59 [debug] 14576#0: *358792 http header: "Host: A.B.C" 2017/01/14 02:46:59 [debug] 14576#0: *358792 http header: "Content-Length: 45" 2017/01/14 02:46:59 [debug] 14576#0: *358792 http header: "Expect: 100-continue" 2017/01/14 02:46:59 [debug] 14576#0: *358792 http header: "Connection: Keep-Alive" 2017/01/14 02:46:59 [debug] 14576#0: *358792 http header done 2017/01/14 02:46:59 [debug] 14576#0: *358792 event timer del: 117: 1484362078365 2017/01/14 02:46:59 [debug] 14576#0: *358792 generic phase: 0 2017/01/14 02:46:59 [debug] 14576#0: *358792 rewrite phase: 1 2017/01/14 02:46:59 [debug] 14576#0: *358792 http cleanup add: 00000000050F8C98 2017/01/14 02:46:59 [debug] 14576#0: *358792 http script value (post filter): "01010101010101010101010101010101" … 2017/01/14 02:46:59 [debug] 14576#0: *358792 lua reset ctx … 2017/01/14 02:46:59 [debug] 14576#0: *358792 test location: "/" 2017/01/14 02:46:59 [debug] 14576#0: *358792 test location: “a/b” 2017/01/14 02:46:59 [debug] 14576#0: *358792 test location: “c/d/“ 2017/01/14 02:46:59 [debug] 14576#0: *358792 test location: “f” 2017/01/14 02:46:59 [debug] 14576#0: *358792 test location: “g” 2017/01/14 02:46:59 [debug] 14576#0: *358792 using configuration "/" 2017/01/14 02:46:59 [debug] 14576#0: *358792 http cl:45 max:1048576 2017/01/14 02:46:59 [debug] 14576#0: *358792 rewrite phase: 3 2017/01/14 02:46:59 [debug] 14576#0: *358792 http script var 2017/01/14 02:46:59 [debug] 14576#0: *358792 http script regex: "^Abc$" 2017/01/14 02:46:59 [notice] 14576#0: *358792 "^Abc$" does not match "", client: X.X.X.X, server: A.B.C, request: "POST /X/Y/Z?k1=v1&k2=v2 HTTP/1.1", host: "A.B.C" 2017/01/14 02:46:59 [debug] 14576#0: *358792 http script if 2017/01/14 02:46:59 [debug] 14576#0: *358792 http script if: false 2017/01/14 02:46:59 [debug] 14576#0: *358792 rewrite phase: 4 2017/01/14 02:46:59 [debug] 14576#0: *358792 headers more rewrite handler, uri “/X/Y/Z” 2017/01/14 02:46:59 [debug] 14576#0: *358792 post rewrite phase: 5 2017/01/14 02:46:59 [debug] 14576#0: *358792 generic phase: 6 2017/01/14 02:46:59 [debug] 14576#0: *358792 generic phase: 7 2017/01/14 02:46:59 [debug] 14576#0: *358792 generic phase: 8 2017/01/14 02:46:59 [debug] 14576#0: *358792 access phase: 9 2017/01/14 02:46:59 [debug] 14576#0: *358792 access phase: 10 2017/01/14 02:46:59 [debug] 14576#0: *358792 post access phase: 11 2017/01/14 02:46:59 [debug] 14576#0: *358792 send 100 Continue 2017/01/14 02:46:59 [debug] 14576#0: *358792 SSL to write: 25 2017/01/14 02:46:59 [debug] 14576#0: *358792 SSL_write: -1 2017/01/14 02:46:59 [debug] 14576#0: *358792 SSL_get_error: 5 2017/01/14 02:46:59 [info] 14576#0: *358792 SSL_write() failed (SSL:) (32: Broken pipe), client: X.X.X.X, server: A.B.C, request: "POST /X/Y/Z?k1=v1&k2=v2 HTTP/1.1", host: "A.B.C" 2017/01/14 02:46:59 [debug] 14576#0: *358792 http finalize request: 500, "/X/Y/Z?k1=v1&k2=v2" a:1, c:1 2017/01/14 02:46:59 [debug] 14576#0: *358792 http special response: 500, "/X/Y/Z?k1=v1&k2=v2" 2017/01/14 02:46:59 [debug] 14576#0: *358792 minutes: "/static/error/500.html?" 2017/01/14 02:46:59 [debug] 14576#0: *358792 rewrite phase: 1 2017/01/14 02:46:59 [debug] 14576#0: *358792 posix_memalign: 00000000036573A0:4096 @16 2017/01/14 02:46:59 [debug] 14576#0: *358792 http cleanup add: 0000000003F43DC0 2017/01/14 02:46:59 [debug] 14576#0: *358792 http script value (post filter): "01010101010101010101010101010101" … 2017/01/14 02:46:59 [debug] 14576#0: *358792 test location: "/" 2017/01/14 02:46:59 [debug] 14576#0: *358792 test location: “a/b” 2017/01/14 02:46:59 [debug] 14576#0: *358792 test location: “c/d/“ 2017/01/14 02:46:59 [debug] 14576#0: *358792 test location: "static" 2017/01/14 02:46:59 [debug] 14576#0: *358792 test location: “/f” 2017/01/14 02:46:59 [debug] 14576#0: *358792 using configuration "/static/error" 2017/01/14 02:46:59 [debug] 14576#0: *358792 http cl:45 max:1048576 2017/01/14 02:46:59 [debug] 14576#0: *358792 rewrite phase: 3 2017/01/14 02:46:59 [debug] 14576#0: *358792 rewrite phase: 4 2017/01/14 02:46:59 [debug] 14576#0: *358792 headers more rewrite handler, uri "/static/error/500.html" 2017/01/14 02:46:59 [debug] 14576#0: *358792 post rewrite phase: 5 2017/01/14 02:46:59 [debug] 14576#0: *358792 generic phase: 6 2017/01/14 02:46:59 [debug] 14576#0: *358792 generic phase: 7 2017/01/14 02:46:59 [debug] 14576#0: *358792 generic phase: 8 2017/01/14 02:46:59 [debug] 14576#0: *358792 access phase: 9 2017/01/14 02:46:59 [debug] 14576#0: *358792 access phase: 10 2017/01/14 02:46:59 [debug] 14576#0: *358792 post access phase: 11 2017/01/14 02:46:59 [debug] 14576#0: *358792 content phase: 12 2017/01/14 02:46:59 [debug] 14576#0: *358792 content phase: 13 2017/01/14 02:46:59 [debug] 14576#0: *358792 content phase: 14 2017/01/14 02:46:59 [debug] 14576#0: *358792 content phase: 15 2017/01/14 02:46:59 [debug] 14576#0: *358792 http filename: "/static/error/500.html" 2017/01/14 02:46:59 [debug] 14576#0: *358792 add cleanup: 0000000003657640 2017/01/14 02:46:59 [debug] 14576#0: *358792 http static fd: 136 2017/01/14 02:46:59 [debug] 14576#0: *358792 http set discard body 2017/01/14 02:46:59 [debug] 14576#0: *358792 http read discarded body 2017/01/14 02:46:59 [debug] 14576#0: *358792 ngx_http_streaming_header_filter() 2017/01/14 02:46:59 [debug] 14576#0: *358792 ip tos: 0x80 2017/01/14 02:46:59 [debug] 14576#0: *358792 headers more header filter, uri "/static/error/500.html" … 2017/01/14 02:46:59 [debug] 14576#0: *358792 lua header filter for user lua code, uri "/static/error/500.html" 2017/01/14 02:46:59 [debug] 14576#0: *358792 lua capture header filter, uri "/static/error/500.html" 2017/01/14 02:46:59 [debug] 14576#0: *358792 HTTP/1.1 500 Internal Server Error 2017/01/14 02:46:59 [debug] 14576#0: *358792 write new buf t:1 f:0 0000000003657930, pos 0000000003657930, size: 300 file: 0, size: 0 2017/01/14 02:46:59 [debug] 14576#0: *358792 http write filter: l:0 f:0 s:300 2017/01/14 02:46:59 [debug] 14576#0: *358792 http output filter "/static/error/500.html?" 2017/01/14 02:46:59 [debug] 14576#0: *358792 http copy filter: "/static/error/500.html?" 2017/01/14 02:46:59 [debug] 14576#0: *358792 malloc: 0000000004E14180:14343 2017/01/14 02:46:59 [debug] 14576#0: *358792 read: 136, 0000000004E14180, 14343, 0 2017/01/14 02:46:59 [debug] 14576#0: *358792 ngx_http_streaming_body_filter() 2017/01/14 02:46:59 [debug] 14576#0: *358792 lua capture body filter, uri "/static/error/500.html" 2017/01/14 02:46:59 [debug] 14576#0: *358792 http postpone filter "/static/error/500.html?" 0000000003657B58 2017/01/14 02:46:59 [debug] 14576#0: *358792 write old buf t:1 f:0 0000000003657930, pos 0000000003657930, size: 300 file: 0, size: 0 2017/01/14 02:46:59 [debug] 14576#0: *358792 write new buf t:1 f:0 0000000004E14180, pos 0000000004E14180, size: 14343 file: 0, size: 0 2017/01/14 02:46:59 [debug] 14576#0: *358792 http write filter: l:1 f:0 s:14643 2017/01/14 02:46:59 [debug] 14576#0: *358792 http write filter limit 0 2017/01/14 02:46:59 [debug] 14576#0: *358792 posix_memalign: 0000000003FD5F10:512 @16 2017/01/14 02:46:59 [debug] 14576#0: *358792 malloc: 0000000003D15350:16384 2017/01/14 02:46:59 [debug] 14576#0: *358792 SSL buf copy: 300 2017/01/14 02:46:59 [debug] 14576#0: *358792 SSL buf copy: 14343 2017/01/14 02:46:59 [debug] 14576#0: *358792 SSL to write: 14643 2017/01/14 02:46:59 [debug] 14576#0: *358792 SSL_write: -1 2017/01/14 02:46:59 [debug] 14576#0: *358792 SSL_get_error: 1 2017/01/14 02:46:59 [crit] 14576#0: *358792 SSL_write() failed (SSL: error:1409F07F:SSL routines:ssl3_write_pending:bad write retry) while sending response to client, client: X.X.X.X, server: A.B.C, request: "POST /X/Y/Z?k1=v1&k2=v2 HTTP/1.1", host: "A.B.C" 2017/01/14 02:46:59 [debug] 14576#0: *358792 http write filter FFFFFFFFFFFFFFFF 2017/01/14 02:46:59 [debug] 14576#0: *358792 http copy filter: -1 "/static/error/500.html?" 2017/01/14 02:46:59 [debug] 14576#0: *358792 http finalize request: -1, "/static/error/500.html?" a:1, c:2 2017/01/14 02:46:59 [debug] 14576#0: *358792 http terminate request count:2 2017/01/14 02:46:59 [debug] 14576#0: *358792 lua request cleanup: forcible=0 2017/01/14 02:46:59 [debug] 14576#0: *358792 lua request cleanup: forcible=0 2017/01/14 02:46:59 [debug] 14576#0: *358792 http terminate cleanup count:2 blk:0 2017/01/14 02:46:59 [debug] 14576#0: *358792 http finalize request: -4, "/static/error/500.html?" a:1, c:2 2017/01/14 02:46:59 [debug] 14576#0: *358792 http request count:2 blk:0 2017/01/14 02:46:59 [debug] 14576#0: *358792 http posted request: "/static/error/500.html?" 2017/01/14 02:46:59 [debug] 14576#0: *358792 http terminate handler count:1 2017/01/14 02:46:59 [debug] 14576#0: *358792 http request count:1 blk:0 2017/01/14 02:46:59 [debug] 14576#0: *358792 http close request 2017/01/14 02:46:59 [debug] 14576#0: *358792 lua log handler, uri:"/static/error/500.html" c:0 2017/01/14 02:46:59 [debug] 14576#0: *358792 http log handler 2017/01/14 02:46:59 [debug] 14576#0: *358792 run cleanup: 0000000003657640 2017/01/14 02:46:59 [debug] 14576#0: *358792 file cleanup: fd:136 2017/01/14 02:46:59 [debug] 14576#0: *358792 free: 0000000004E14180 2017/01/14 02:46:59 [debug] 14576#0: *358792 free: 00000000050F7CE0, unused: 0 2017/01/14 02:46:59 [debug] 14576#0: *358792 free: 0000000003F42E70, unused: 0 2017/01/14 02:46:59 [debug] 14576#0: *358792 free: 00000000036573A0, unused: 1448 2017/01/14 02:46:59 [debug] 14576#0: *358792 close http connection: 117 2017/01/14 02:46:59 [debug] 14576#0: *358792 SSL_shutdown: 1 2017/01/14 02:46:59 [debug] 14576#0: *358792 reusable connection: 0 2017/01/14 02:46:59 [debug] 14576#0: *358792 free: 0000000003D15350 2017/01/14 02:46:59 [debug] 14576#0: *358792 free: 00000000050FFC60 2017/01/14 02:46:59 [debug] 14576#0: *358792 free: 0000000003F390C0, unused: 8 2017/01/14 02:46:59 [debug] 14576#0: *358792 free: 0000000003FD5F10, unused: 384