2013/12/28 19:00:27 [debug] 3727#0: epoll: fd:6 ev:0001 d:00007FA5F4C5C010 2013/12/28 19:00:27 [debug] 3727#0: accept on 0.0.0.0:443, ready: 0 2013/12/28 19:00:27 [debug] 3727#0: posix_memalign: 00000000018FEC70:256 @16 2013/12/28 19:00:27 [debug] 3727#0: *41 accept: 192.168.29.1 fd:3 2013/12/28 19:00:27 [debug] 3727#0: *41 event timer add: 3: 60000:1388257287001 2013/12/28 19:00:27 [debug] 3727#0: *41 reusable connection: 1 2013/12/28 19:00:27 [debug] 3727#0: *41 epoll add event: fd:3 op:1 ev:80000001 2013/12/28 19:00:27 [debug] 3727#0: timer delta: 141425 2013/12/28 19:00:27 [debug] 3727#0: posted events 0000000000000000 2013/12/28 19:00:27 [debug] 3727#0: worker cycle 2013/12/28 19:00:27 [debug] 3727#0: epoll timer: 60000 2013/12/28 19:00:27 [debug] 3727#0: epoll: fd:3 ev:0001 d:00007FA5F4C5C190 2013/12/28 19:00:27 [debug] 3727#0: *41 http check ssl handshake 2013/12/28 19:00:27 [debug] 3727#0: *41 http recv(): 1 2013/12/28 19:00:27 [debug] 3727#0: *41 https ssl handshake: 0x16 2013/12/28 19:00:27 [debug] 3727#0: *41 posix_memalign: 00000000018FBDD0:256 @16 2013/12/28 19:00:27 [debug] 3727#0: *41 SSL server name: "192.168.29.128" 2013/12/28 19:00:27 [debug] 3727#0: *41 SSL_do_handshake: -1 2013/12/28 19:00:27 [debug] 3727#0: *41 SSL_get_error: 2 2013/12/28 19:00:27 [debug] 3727#0: *41 reusable connection: 0 2013/12/28 19:00:27 [debug] 3727#0: timer delta: 1 2013/12/28 19:00:27 [debug] 3727#0: posted events 0000000000000000 2013/12/28 19:00:27 [debug] 3727#0: worker cycle 2013/12/28 19:00:27 [debug] 3727#0: epoll timer: 59999 2013/12/28 19:00:28 [debug] 3727#0: epoll: fd:3 ev:0001 d:00007FA5F4C5C190 2013/12/28 19:00:28 [debug] 3727#0: *41 SSL handshake handler: 0 2013/12/28 19:00:28 [debug] 3727#0: *41 verify:1, error:0, depth:1, subject:"/C=GB/ST=England/L=London/O=ITS/OU=test/CN=root.invalid",issuer: "/C=GB/ST=England/L=London/O=ITS/OU=test/CN=root.invalid" 2013/12/28 19:00:28 [debug] 3727#0: *41 verify:1, error:0, depth:0, subject:"/C=GB/ST=England/L=London/O=ITS/OU=test/CN=Demo Client",issuer: "/C=GB/ST=England/L=London/O=ITS/OU=test/CN=root.invalid" 2013/12/28 19:00:28 [debug] 3727#0: *41 SSL_do_handshake: 1 2013/12/28 19:00:28 [debug] 3727#0: *41 SSL: TLSv1.2, cipher: "ECDHE-RSA-AES128-SHA256 TLSv1.2 Kx=ECDH Au=RSA Enc=AES(128) Mac=SHA256" 2013/12/28 19:00:28 [debug] 3727#0: *41 reusable connection: 1 2013/12/28 19:00:28 [debug] 3727#0: *41 http wait request handler 2013/12/28 19:00:28 [debug] 3727#0: *41 malloc: 0000000001949980:1024 2013/12/28 19:00:28 [debug] 3727#0: *41 SSL_read: -1 2013/12/28 19:00:28 [debug] 3727#0: *41 SSL_get_error: 2 2013/12/28 19:00:28 [debug] 3727#0: *41 free: 0000000001949980 2013/12/28 19:00:28 [debug] 3727#0: timer delta: 1452 2013/12/28 19:00:28 [debug] 3727#0: posted events 0000000000000000 2013/12/28 19:00:28 [debug] 3727#0: worker cycle 2013/12/28 19:00:28 [debug] 3727#0: epoll timer: 58547 2013/12/28 19:00:28 [debug] 3727#0: epoll: fd:3 ev:0001 d:00007FA5F4C5C190 2013/12/28 19:00:28 [debug] 3727#0: *41 http wait request handler 2013/12/28 19:00:28 [debug] 3727#0: *41 malloc: 0000000001949980:1024 2013/12/28 19:00:28 [debug] 3727#0: *41 SSL_read: 377 2013/12/28 19:00:28 [debug] 3727#0: *41 SSL_read: -1 2013/12/28 19:00:28 [debug] 3727#0: *41 SSL_get_error: 2 2013/12/28 19:00:28 [debug] 3727#0: *41 reusable connection: 0 2013/12/28 19:00:28 [debug] 3727#0: *41 posix_memalign: 00000000018E4A10:4096 @16 2013/12/28 19:00:28 [debug] 3727#0: *41 http process request line 2013/12/28 19:00:28 [debug] 3727#0: *41 http request line: "GET / HTTP/1.1" 2013/12/28 19:00:28 [debug] 3727#0: *41 http uri: "/" 2013/12/28 19:00:28 [debug] 3727#0: *41 http args: "" 2013/12/28 19:00:28 [debug] 3727#0: *41 http exten: "" 2013/12/28 19:00:28 [debug] 3727#0: *41 posix_memalign: 000000000194D8B0:4096 @16 2013/12/28 19:00:28 [debug] 3727#0: *41 http process request header line 2013/12/28 19:00:28 [debug] 3727#0: *41 http header: "Host: 192.168.29.128" 2013/12/28 19:00:28 [debug] 3727#0: *41 http header: "Pragma: no-cache" 2013/12/28 19:00:28 [debug] 3727#0: *41 http header: "Accept-Encoding: gzip, deflate" 2013/12/28 19:00:28 [debug] 3727#0: *41 http header: "Connection: keep-alive" 2013/12/28 19:00:28 [debug] 3727#0: *41 http header: "Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8" 2013/12/28 19:00:28 [debug] 3727#0: *41 http header: "User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_1) AppleWebKit/537.73.11 (KHTML, like Gecko) Version/7.0.1 Safari/537.73.11" 2013/12/28 19:00:28 [debug] 3727#0: *41 http header: "Accept-Language: en-us" 2013/12/28 19:00:28 [debug] 3727#0: *41 http header: "DNT: 1" 2013/12/28 19:00:28 [debug] 3727#0: *41 http header: "Cache-Control: no-cache" 2013/12/28 19:00:28 [debug] 3727#0: *41 http header done 2013/12/28 19:00:28 [debug] 3727#0: *41 event timer del: 3: 1388257287001 2013/12/28 19:00:28 [debug] 3727#0: *41 generic phase: 0 2013/12/28 19:00:28 [debug] 3727#0: *41 rewrite phase: 1 2013/12/28 19:00:28 [debug] 3727#0: *41 test location: "/" 2013/12/28 19:00:28 [debug] 3727#0: *41 test location: ~ "^(.+\.php)(.*)$" 2013/12/28 19:00:28 [debug] 3727#0: *41 using configuration "/" 2013/12/28 19:00:28 [debug] 3727#0: *41 http cl:-1 max:1048576 2013/12/28 19:00:28 [debug] 3727#0: *41 rewrite phase: 3 2013/12/28 19:00:28 [debug] 3727#0: *41 post rewrite phase: 4 2013/12/28 19:00:28 [debug] 3727#0: *41 generic phase: 5 2013/12/28 19:00:28 [debug] 3727#0: *41 generic phase: 6 2013/12/28 19:00:28 [debug] 3727#0: *41 generic phase: 7 2013/12/28 19:00:28 [debug] 3727#0: *41 access phase: 8 2013/12/28 19:00:28 [debug] 3727#0: *41 access phase: 9 2013/12/28 19:00:28 [debug] 3727#0: *41 post access phase: 10 2013/12/28 19:00:28 [debug] 3727#0: *41 content phase: 11 2013/12/28 19:00:28 [debug] 3727#0: *41 content phase: 12 2013/12/28 19:00:28 [debug] 3727#0: *41 open index "/usr/share/nginx/html/index.html" 2013/12/28 19:00:28 [debug] 3727#0: *41 internal redirect: "/index.html?" 2013/12/28 19:00:28 [debug] 3727#0: *41 rewrite phase: 1 2013/12/28 19:00:28 [debug] 3727#0: *41 test location: "/" 2013/12/28 19:00:28 [debug] 3727#0: *41 test location: ~ "^(.+\.php)(.*)$" 2013/12/28 19:00:28 [debug] 3727#0: *41 using configuration "/" 2013/12/28 19:00:28 [debug] 3727#0: *41 http cl:-1 max:1048576 2013/12/28 19:00:28 [debug] 3727#0: *41 rewrite phase: 3 2013/12/28 19:00:28 [debug] 3727#0: *41 post rewrite phase: 4 2013/12/28 19:00:28 [debug] 3727#0: *41 generic phase: 5 2013/12/28 19:00:28 [debug] 3727#0: *41 generic phase: 6 2013/12/28 19:00:28 [debug] 3727#0: *41 generic phase: 7 2013/12/28 19:00:28 [debug] 3727#0: *41 access phase: 8 2013/12/28 19:00:28 [debug] 3727#0: *41 access phase: 9 2013/12/28 19:00:28 [debug] 3727#0: *41 post access phase: 10 2013/12/28 19:00:28 [debug] 3727#0: *41 content phase: 11 2013/12/28 19:00:28 [debug] 3727#0: *41 content phase: 12 2013/12/28 19:00:28 [debug] 3727#0: *41 content phase: 13 2013/12/28 19:00:28 [debug] 3727#0: *41 content phase: 14 2013/12/28 19:00:28 [debug] 3727#0: *41 content phase: 15 2013/12/28 19:00:28 [debug] 3727#0: *41 content phase: 16 2013/12/28 19:00:28 [debug] 3727#0: *41 http filename: "/usr/share/nginx/html/index.html" 2013/12/28 19:00:28 [debug] 3727#0: *41 add cleanup: 00000000018E5778 2013/12/28 19:00:28 [debug] 3727#0: *41 http static fd: 10 2013/12/28 19:00:28 [debug] 3727#0: *41 http set discard body 2013/12/28 19:00:28 [debug] 3727#0: *41 HTTP/1.1 200 OK Date: Sat, 28 Dec 2013 19:00:28 GMT 2013/12/28 19:00:28 [debug] 3727#0: *41 write new buf t:1 f:0 000000000194DC90, pos 000000000194DC90, size: 237 file: 0, size: 0 2013/12/28 19:00:28 [debug] 3727#0: *41 http write filter: l:0 f:0 s:237 2013/12/28 19:00:28 [debug] 3727#0: *41 http output filter "/index.html?" 2013/12/28 19:00:28 [debug] 3727#0: *41 http copy filter: "/index.html?" 2013/12/28 19:00:28 [debug] 3727#0: *41 read: 10, 000000000194DDE0, 612, 0 2013/12/28 19:00:28 [debug] 3727#0: *41 http postpone filter "/index.html?" 00000000018E59D8 2013/12/28 19:00:28 [debug] 3727#0: *41 write old buf t:1 f:0 000000000194DC90, pos 000000000194DC90, size: 237 file: 0, size: 0 2013/12/28 19:00:28 [debug] 3727#0: *41 write new buf t:1 f:1 000000000194DDE0, pos 000000000194DDE0, size: 612 file: 0, size: 612 2013/12/28 19:00:28 [debug] 3727#0: *41 http write filter: l:1 f:0 s:849 2013/12/28 19:00:28 [debug] 3727#0: *41 http write filter limit 0 2013/12/28 19:00:28 [debug] 3727#0: *41 posix_memalign: 000000000194BB50:256 @16 2013/12/28 19:00:28 [debug] 3727#0: *41 malloc: 000000000193C2D0:16384 2013/12/28 19:00:28 [debug] 3727#0: *41 SSL buf copy: 237 2013/12/28 19:00:28 [debug] 3727#0: *41 SSL buf copy: 612 2013/12/28 19:00:28 [debug] 3727#0: *41 SSL to write: 849 2013/12/28 19:00:28 [debug] 3727#0: *41 SSL_write: 849 2013/12/28 19:00:28 [debug] 3727#0: *41 http write filter 0000000000000000 2013/12/28 19:00:28 [debug] 3727#0: *41 http copy filter: 0 "/index.html?" 2013/12/28 19:00:28 [debug] 3727#0: *41 http finalize request: 0, "/index.html?" a:1, c:2 2013/12/28 19:00:28 [debug] 3727#0: *41 http request count:2 blk:0 2013/12/28 19:00:28 [debug] 3727#0: *41 http finalize request: -4, "/index.html?" a:1, c:1 2013/12/28 19:00:28 [debug] 3727#0: *41 set http keepalive handler 2013/12/28 19:00:28 [debug] 3727#0: *41 http close request 2013/12/28 19:00:28 [debug] 3727#0: *41 http log handler 2013/12/28 19:00:28 [debug] 3727#0: *41 run cleanup: 00000000018E5778 2013/12/28 19:00:28 [debug] 3727#0: *41 file cleanup: fd:10 2013/12/28 19:00:28 [debug] 3727#0: *41 free: 00000000018E4A10, unused: 24 2013/12/28 19:00:28 [debug] 3727#0: *41 free: 000000000194D8B0, unused: 1921 2013/12/28 19:00:28 [debug] 3727#0: *41 free: 0000000001949980 2013/12/28 19:00:28 [debug] 3727#0: *41 hc free: 0000000000000000 0 2013/12/28 19:00:28 [debug] 3727#0: *41 hc busy: 0000000000000000 0 2013/12/28 19:00:28 [debug] 3727#0: *41 free: 000000000193C2D0 2013/12/28 19:00:28 [debug] 3727#0: *41 tcp_nodelay 2013/12/28 19:00:28 [debug] 3727#0: *41 reusable connection: 1 2013/12/28 19:00:28 [debug] 3727#0: *41 event timer add: 3: 65000:1388257293456 2013/12/28 19:00:28 [debug] 3727#0: timer delta: 2 2013/12/28 19:00:28 [debug] 3727#0: posted events 0000000000000000 2013/12/28 19:00:28 [debug] 3727#0: worker cycle 2013/12/28 19:00:28 [debug] 3727#0: epoll timer: 65000