Another run with Tomcat, fresh log: 2014/02/18 15:58:53 [debug] 12993#0: epoll add event: fd:9 op:1 ev:00002001 2014/02/18 15:58:57 [debug] 12993#0: post event 00007F19759D4078 2014/02/18 15:58:57 [debug] 12993#0: delete posted event 00007F19759D4078 2014/02/18 15:58:57 [debug] 12993#0: accept on 192.168.89.175:443, ready: 1 2014/02/18 15:58:57 [debug] 12993#0: posix_memalign: 0000000001CF4860:256 @16 2014/02/18 15:58:57 [debug] 12993#0: *1 accept: 192.168.76.46 fd:15 2014/02/18 15:58:57 [debug] 12993#0: posix_memalign: 0000000001CF4300:256 @16 2014/02/18 15:58:57 [debug] 12993#0: *1 event timer add: 15: 60000:1392735597357 2014/02/18 15:58:57 [debug] 12993#0: *1 reusable connection: 1 2014/02/18 15:58:57 [debug] 12993#0: *1 epoll add event: fd:15 op:1 ev:80002001 2014/02/18 15:58:57 [debug] 12993#0: accept() not ready (11: Resource temporarily unavailable) 2014/02/18 15:58:57 [debug] 12993#0: *1 post event 00007F19759D4148 2014/02/18 15:58:57 [debug] 12993#0: *1 delete posted event 00007F19759D4148 2014/02/18 15:58:57 [debug] 12993#0: *1 http check ssl handshake 2014/02/18 15:58:57 [debug] 12993#0: *1 http recv(): 1 2014/02/18 15:58:57 [debug] 12993#0: *1 https ssl handshake: 0x16 2014/02/18 15:58:57 [debug] 12993#0: *1 ssl get session: C26B2FD1:32 2014/02/18 15:58:57 [debug] 12993#0: *1 SSL server name: "www.example.org" 2014/02/18 15:58:57 [debug] 12993#0: *1 SSL_do_handshake: 0 2014/02/18 15:58:57 [debug] 12993#0: *1 SSL_get_error: 5 2014/02/18 15:58:57 [info] 12993#0: *1 peer closed connection in SSL handshake while SSL handshaking, client: 192.168.76.46, server: 192.168.89.175:443 2014/02/18 15:58:57 [debug] 12993#0: *1 close http connection: 15 2014/02/18 15:58:57 [debug] 12993#0: *1 SSL_shutdown: 1 2014/02/18 15:58:57 [debug] 12993#0: *1 event timer del: 15: 1392735597357 2014/02/18 15:58:57 [debug] 12993#0: *1 reusable connection: 0 2014/02/18 15:58:57 [debug] 12993#0: *1 free: 0000000001CF4860, unused: 16 2014/02/18 15:58:57 [debug] 12993#0: *1 free: 0000000001CF4300, unused: 114 2014/02/18 15:58:57 [debug] 12993#0: post event 00007F19759D4078 2014/02/18 15:58:57 [debug] 12993#0: delete posted event 00007F19759D4078 2014/02/18 15:58:57 [debug] 12993#0: accept on 192.168.89.175:443, ready: 1 2014/02/18 15:58:57 [debug] 12993#0: posix_memalign: 0000000001C56F00:256 @16 2014/02/18 15:58:57 [debug] 12993#0: *2 accept: 192.168.76.46 fd:15 2014/02/18 15:58:57 [debug] 12993#0: posix_memalign: 0000000001CD8F70:256 @16 2014/02/18 15:58:57 [debug] 12993#0: *2 event timer add: 15: 60000:1392735597365 2014/02/18 15:58:57 [debug] 12993#0: *2 reusable connection: 1 2014/02/18 15:58:57 [debug] 12993#0: *2 epoll add event: fd:15 op:1 ev:80002001 2014/02/18 15:58:57 [debug] 12993#0: accept() not ready (11: Resource temporarily unavailable) 2014/02/18 15:58:57 [debug] 12993#0: *2 post event 00007F19759D4148 2014/02/18 15:58:57 [debug] 12993#0: *2 delete posted event 00007F19759D4148 2014/02/18 15:58:57 [debug] 12993#0: *2 http check ssl handshake 2014/02/18 15:58:57 [debug] 12993#0: *2 http recv(): 1 2014/02/18 15:58:57 [debug] 12993#0: *2 https ssl handshake: 0x16 2014/02/18 15:58:57 [debug] 12993#0: *2 ssl get session: C26B2FD1:32 2014/02/18 15:58:57 [debug] 12993#0: *2 SSL server name: "www.example.org" 2014/02/18 15:58:57 [debug] 12993#0: *2 SSL NPN advertised 2014/02/18 15:58:57 [debug] 12993#0: *2 SSL_do_handshake: -1 2014/02/18 15:58:57 [debug] 12993#0: *2 SSL_get_error: 2 2014/02/18 15:58:57 [debug] 12993#0: *2 reusable connection: 0 2014/02/18 15:58:57 [debug] 12993#0: *2 post event 00007F19759D4148 2014/02/18 15:58:57 [debug] 12993#0: *2 delete posted event 00007F19759D4148 2014/02/18 15:58:57 [debug] 12993#0: *2 SSL handshake handler: 0 2014/02/18 15:58:57 [debug] 12993#0: *2 SSL_do_handshake: 1 2014/02/18 15:58:57 [debug] 12993#0: *2 SSL: TLSv1.2, cipher: "ECDHE-RSA-AES128-GCM-SHA256 TLSv1.2 Kx=ECDH Au=RSA Enc=AESGCM(128) Mac=AEAD" 2014/02/18 15:58:57 [debug] 12993#0: *2 init spdy request 2014/02/18 15:58:57 [debug] 12993#0: *2 malloc: 0000000001C5FB10:424 2014/02/18 15:58:57 [debug] 12993#0: *2 malloc: 0000000001D451A0:9552 2014/02/18 15:58:57 [debug] 12993#0: *2 malloc: 0000000001C63930:5928 2014/02/18 15:58:57 [debug] 12993#0: *2 malloc: 0000000001CD9260:4096 2014/02/18 15:58:57 [debug] 12993#0: *2 malloc: 0000000001D47700:4096 2014/02/18 15:58:57 [debug] 12993#0: *2 malloc: 0000000001D4EAD0:4096 2014/02/18 15:58:57 [debug] 12993#0: *2 malloc: 0000000001D4FAE0:4096 2014/02/18 15:58:57 [debug] 12993#0: *2 posix_memalign: 0000000001D50AF0:4096 @16 2014/02/18 15:58:57 [debug] 12993#0: *2 posix_memalign: 0000000001CF4300:256 @16 2014/02/18 15:58:57 [debug] 12993#0: *2 add cleanup: 0000000001CF4320 2014/02/18 15:58:57 [debug] 12993#0: *2 spdy create SETTINGS frame 2014/02/18 15:58:57 [debug] 12993#0: *2 spdy write WINDOW_UPDATE sid:0 delta:2147418111 2014/02/18 15:58:57 [debug] 12993#0: *2 spdy read handler 2014/02/18 15:58:57 [debug] 12993#0: *2 SSL_read: -1 2014/02/18 15:58:57 [debug] 12993#0: *2 SSL_get_error: 2 2014/02/18 15:58:57 [debug] 12993#0: *2 spdy frame out: 0000000001D50D00 sid:0 prio:0 bl:0 len:8 2014/02/18 15:58:57 [debug] 12993#0: *2 spdy frame out: 0000000001D50C40 sid:0 prio:0 bl:0 len:20 2014/02/18 15:58:57 [debug] 12993#0: *2 malloc: 0000000001D5C180:16384 2014/02/18 15:58:57 [debug] 12993#0: *2 SSL buf copy: 28 2014/02/18 15:58:57 [debug] 12993#0: *2 SSL buf copy: 16 2014/02/18 15:58:57 [debug] 12993#0: *2 SSL to write: 44 2014/02/18 15:58:57 [debug] 12993#0: *2 SSL_write: 44 2014/02/18 15:58:57 [debug] 12993#0: *2 spdy frame sent: 0000000001D50C40 sid:0 bl:0 len:20 2014/02/18 15:58:57 [debug] 12993#0: *2 spdy frame sent: 0000000001D50D00 sid:0 bl:0 len:8 2014/02/18 15:58:57 [debug] 12993#0: *2 free: 0000000001D50AF0, unused: 3392 2014/02/18 15:58:57 [debug] 12993#0: *2 free: 0000000001D5C180 2014/02/18 15:58:57 [debug] 12993#0: *2 reusable connection: 1 2014/02/18 15:58:57 [debug] 12993#0: *2 event timer del: 15: 1392735597365 2014/02/18 15:58:57 [debug] 12993#0: *2 event timer add: 15: 180000:1392735717380 2014/02/18 15:58:57 [debug] 12993#0: *2 post event 00007F19759D4148 2014/02/18 15:58:57 [debug] 12993#0: *2 delete posted event 00007F19759D4148 2014/02/18 15:58:57 [debug] 12993#0: *2 spdy keepalive handler 2014/02/18 15:58:57 [debug] 12993#0: *2 reusable connection: 0 2014/02/18 15:58:57 [debug] 12993#0: *2 posix_memalign: 0000000001D50AF0:4096 @16 2014/02/18 15:58:57 [debug] 12993#0: *2 spdy read handler 2014/02/18 15:58:57 [debug] 12993#0: *2 SSL_read: 36 2014/02/18 15:58:57 [debug] 12993#0: *2 SSL_read: 568 2014/02/18 15:58:57 [debug] 12993#0: *2 SSL_read: -1 2014/02/18 15:58:57 [debug] 12993#0: *2 SSL_get_error: 2 2014/02/18 15:58:57 [debug] 12993#0: *2 spdy process frame head:80030004 f:0 l:12 2014/02/18 15:58:57 [debug] 12993#0: *2 spdy SETTINGS frame consists of 1 entries 2014/02/18 15:58:57 [debug] 12993#0: *2 spdy SETTINGS entry fl:0 id:7 val:65536 2014/02/18 15:58:57 [debug] 12993#0: *2 spdy process frame head:80030009 f:0 l:8 2014/02/18 15:58:57 [debug] 12993#0: *2 spdy WINDOW_UPDATE sid:0 delta:268369920 2014/02/18 15:58:57 [debug] 12993#0: *2 spdy process frame head:80030001 f:1 l:544 2014/02/18 15:58:57 [debug] 12993#0: *2 spdy SYN_STREAM frame sid:1 prio:2 2014/02/18 15:58:57 [debug] 12993#0: *2 posix_memalign: 0000000001D51B00:4096 @16 2014/02/18 15:58:57 [debug] 12993#0: *2 posix_memalign: 0000000001D52B10:4096 @16 2014/02/18 15:58:57 [debug] 12993#0: *2 spdy process HEADERS 534 of 534 2014/02/18 15:58:57 [debug] 12993#0: *2 malloc: 0000000001D5C180:32768 2014/02/18 15:58:57 [debug] 12993#0: *2 spdy inflateSetDictionary(): 0 2014/02/18 15:58:57 [debug] 12993#0: *2 spdy inflate out: ni:00007F197565225C no:0000000001D52D36 ai:0 ao:505 rc:0 2014/02/18 15:58:57 [debug] 12993#0: *2 spdy HEADERS block consists of 11 entries 2014/02/18 15:58:57 [debug] 12993#0: *2 http uri: "/" 2014/02/18 15:58:57 [debug] 12993#0: *2 http args: "" 2014/02/18 15:58:57 [debug] 12993#0: *2 http exten: "" 2014/02/18 15:58:57 [debug] 12993#0: *2 spdy http request line: "GET / HTTP/1.1" 2014/02/18 15:58:57 [debug] 12993#0: *2 http header: "host: www.example.org" 2014/02/18 15:58:57 [debug] 12993#0: *2 http header: "user-agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:27.0) Gecko/20100101 Firefox/27.0" 2014/02/18 15:58:57 [debug] 12993#0: *2 http header: "cache-control: max-age=0" 2014/02/18 15:58:57 [debug] 12993#0: *2 http header: "accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8" 2014/02/18 15:58:57 [debug] 12993#0: *2 http header: "accept-language: de-de,de;q=0.8,en-us;q=0.5,en;q=0.3" 2014/02/18 15:58:57 [debug] 12993#0: *2 http header: "cookie: cfid=b0fc4a14-0812-48b6-aea7-077c7b61cca7; cftoken=0; _ga=GA1.2.982493482.1392732645; JSESSIONID=5ln6ihdqossy18j3j9ouz680c" 2014/02/18 15:58:57 [debug] 12993#0: *2 http header: "dnt: 1" 2014/02/18 15:58:57 [debug] 12993#0: *2 generic phase: 0 2014/02/18 15:58:57 [debug] 12993#0: *2 rewrite phase: 1 2014/02/18 15:58:57 [debug] 12993#0: *2 http script regex: "^/\+" 2014/02/18 15:58:57 [notice] 12993#0: *2 "^/\+" does not match "/", client: 192.168.76.46, server: www.example.org, request: "GET / HTTP/1.1", host: "www.example.org" 2014/02/18 15:58:57 [debug] 12993#0: *2 http script var 2014/02/18 15:58:57 [debug] 12993#0: *2 http script var: "GET" 2014/02/18 15:58:57 [debug] 12993#0: *2 http script regex: "^(GET|HEAD|POST)$" 2014/02/18 15:58:57 [notice] 12993#0: *2 "^(GET|HEAD|POST)$" matches "GET", client: 192.168.76.46, server: www.example.org, request: "GET / HTTP/1.1", host: "www.example.org" 2014/02/18 15:58:57 [debug] 12993#0: *2 http script if 2014/02/18 15:58:57 [debug] 12993#0: *2 http script if: false 2014/02/18 15:58:57 [debug] 12993#0: *2 test location: "/" 2014/02/18 15:58:57 [debug] 12993#0: *2 test location: ~ "\.(?:png|jpe?g)$" 2014/02/18 15:58:57 [debug] 12993#0: *2 test location: ~ "\.php$" 2014/02/18 15:58:57 [debug] 12993#0: *2 test location: ~ "\.(cfm|cfml|cfc|jsp|cfr)(.*)$" 2014/02/18 15:58:57 [debug] 12993#0: *2 test location: ~ "/\." 2014/02/18 15:58:57 [debug] 12993#0: *2 test location: ~ "\.(?:eot|ttf|woff|otf|svg)$" 2014/02/18 15:58:57 [debug] 12993#0: *2 test location: ~ "\.(?:css|js|png|jpe?g|ico|gif)$" 2014/02/18 15:58:57 [debug] 12993#0: *2 test location: ~ "\.(aspx|asp|jsp|cgi)$" 2014/02/18 15:58:57 [debug] 12993#0: *2 using configuration "/" 2014/02/18 15:58:57 [debug] 12993#0: *2 http cl:-1 max:1048576 2014/02/18 15:58:57 [debug] 12993#0: *2 rewrite phase: 3 2014/02/18 15:58:57 [debug] 12993#0: *2 post rewrite phase: 4 2014/02/18 15:58:57 [debug] 12993#0: *2 generic phase: 5 2014/02/18 15:58:57 [debug] 12993#0: *2 generic phase: 6 2014/02/18 15:58:57 [debug] 12993#0: *2 generic phase: 7 2014/02/18 15:58:57 [debug] 12993#0: *2 generic phase: 8 2014/02/18 15:58:57 [debug] 12993#0: *2 access phase: 9 2014/02/18 15:58:57 [debug] 12993#0: *2 access phase: 10 2014/02/18 15:58:57 [debug] 12993#0: *2 post access phase: 11 2014/02/18 15:58:57 [debug] 12993#0: *2 try files phase: 12 2014/02/18 15:58:57 [debug] 12993#0: *2 http script var: "/" 2014/02/18 15:58:57 [debug] 12993#0: *2 trying to use file: "/" "/usr/share/nginx/html/example.org/" 2014/02/18 15:58:57 [debug] 12993#0: *2 add cleanup: 0000000001D52A58 2014/02/18 15:58:57 [debug] 12993#0: *2 malloc: 0000000001CF4A60:144 2014/02/18 15:58:57 [debug] 12993#0: *2 malloc: 0000000001CDA7D0:42 2014/02/18 15:58:57 [debug] 12993#0: *2 cached open file: /usr/share/nginx/html/example.org/, fd:-1, c:0, e:0, u:1 2014/02/18 15:58:57 [debug] 12993#0: *2 http script var: "/" 2014/02/18 15:58:57 [debug] 12993#0: *2 trying to use dir: "/" "/usr/share/nginx/html/example.org/" 2014/02/18 15:58:57 [debug] 12993#0: *2 add cleanup: 0000000001D52A90 2014/02/18 15:58:57 [debug] 12993#0: *2 cached open file: /usr/share/nginx/html/example.org/, fd:-1, c:0, e:0, u:2 2014/02/18 15:58:57 [debug] 12993#0: *2 try file uri: "/" 2014/02/18 15:58:57 [debug] 12993#0: *2 content phase: 13 2014/02/18 15:58:57 [debug] 12993#0: *2 content phase: 14 2014/02/18 15:58:57 [debug] 12993#0: *2 open index "/usr/share/nginx/html/example.org/index.cfm" 2014/02/18 15:58:57 [debug] 12993#0: *2 add cleanup: 0000000001D531D0 2014/02/18 15:58:57 [debug] 12993#0: *2 malloc: 0000000001CDF7F0:144 2014/02/18 15:58:57 [debug] 12993#0: *2 malloc: 0000000001CF4CA0:51 2014/02/18 15:58:57 [debug] 12993#0: *2 cached open file: /usr/share/nginx/html/example.org/index.cfm, fd:16, c:1, e:0, u:1 2014/02/18 15:58:57 [debug] 12993#0: *2 internal redirect: "/index.cfm?" 2014/02/18 15:58:57 [debug] 12993#0: *2 rewrite phase: 1 2014/02/18 15:58:57 [debug] 12993#0: *2 http script regex: "^/\+" 2014/02/18 15:58:57 [notice] 12993#0: *2 "^/\+" does not match "/index.cfm", client: 192.168.76.46, server: www.example.org, request: "GET / HTTP/1.1", host: "www.example.org" 2014/02/18 15:58:57 [debug] 12993#0: *2 http script var 2014/02/18 15:58:57 [debug] 12993#0: *2 http script var: "GET" 2014/02/18 15:58:57 [debug] 12993#0: *2 http script regex: "^(GET|HEAD|POST)$" 2014/02/18 15:58:57 [notice] 12993#0: *2 "^(GET|HEAD|POST)$" matches "GET", client: 192.168.76.46, server: www.example.org, request: "GET / HTTP/1.1", host: "www.example.org" 2014/02/18 15:58:57 [debug] 12993#0: *2 http script if 2014/02/18 15:58:57 [debug] 12993#0: *2 http script if: false 2014/02/18 15:58:57 [debug] 12993#0: *2 test location: "/" 2014/02/18 15:58:57 [debug] 12993#0: *2 test location: "core/" 2014/02/18 15:58:57 [debug] 12993#0: *2 test location: "includes/" 2014/02/18 15:58:57 [debug] 12993#0: *2 test location: "templates/" 2014/02/18 15:58:57 [debug] 12993#0: *2 test location: "robots.txt" 2014/02/18 15:58:57 [debug] 12993#0: *2 test location: ~ "\.(?:png|jpe?g)$" 2014/02/18 15:58:57 [debug] 12993#0: *2 test location: ~ "\.php$" 2014/02/18 15:58:57 [debug] 12993#0: *2 test location: ~ "\.(cfm|cfml|cfc|jsp|cfr)(.*)$" 2014/02/18 15:58:57 [debug] 12993#0: *2 using configuration "\.(cfm|cfml|cfc|jsp|cfr)(.*)$" 2014/02/18 15:58:57 [debug] 12993#0: *2 http cl:-1 max:1048576 2014/02/18 15:58:57 [debug] 12993#0: *2 rewrite phase: 3 2014/02/18 15:58:57 [debug] 12993#0: *2 post rewrite phase: 4 2014/02/18 15:58:57 [debug] 12993#0: *2 generic phase: 5 2014/02/18 15:58:57 [debug] 12993#0: *2 generic phase: 6 2014/02/18 15:58:57 [debug] 12993#0: *2 generic phase: 7 2014/02/18 15:58:57 [debug] 12993#0: *2 generic phase: 8 2014/02/18 15:58:57 [debug] 12993#0: *2 access phase: 9 2014/02/18 15:58:57 [debug] 12993#0: *2 access phase: 10 2014/02/18 15:58:57 [debug] 12993#0: *2 post access phase: 11 2014/02/18 15:58:57 [debug] 12993#0: *2 try files phase: 12 2014/02/18 15:58:57 [debug] 12993#0: *2 spdy read request body 2014/02/18 15:58:57 [debug] 12993#0: *2 http init upstream, client timer: 0 2014/02/18 15:58:57 [debug] 12993#0: *2 posix_memalign: 0000000001D64190:4096 @16 2014/02/18 15:58:57 [debug] 12993#0: *2 http script copy: "Host: " 2014/02/18 15:58:57 [debug] 12993#0: *2 http script var: "www.example.org" 2014/02/18 15:58:57 [debug] 12993#0: *2 http script copy: " " 2014/02/18 15:58:57 [debug] 12993#0: *2 http script copy: "X-Forwarded-Host: " 2014/02/18 15:58:57 [debug] 12993#0: *2 http script var: "www.example.org" 2014/02/18 15:58:57 [debug] 12993#0: *2 http script copy: " " 2014/02/18 15:58:57 [debug] 12993#0: *2 http script copy: "X-Forwarded-Server: " 2014/02/18 15:58:57 [debug] 12993#0: *2 http script var: "www.example.org" 2014/02/18 15:58:57 [debug] 12993#0: *2 http script copy: " " 2014/02/18 15:58:57 [debug] 12993#0: *2 http script copy: "X-Forwarded-For: " 2014/02/18 15:58:57 [debug] 12993#0: *2 http script var: "192.168.76.46" 2014/02/18 15:58:57 [debug] 12993#0: *2 http script copy: " " 2014/02/18 15:58:57 [debug] 12993#0: *2 http script copy: "X-Real-IP: " 2014/02/18 15:58:57 [debug] 12993#0: *2 http script var: "192.168.76.46" 2014/02/18 15:58:57 [debug] 12993#0: *2 http script copy: " " 2014/02/18 15:58:57 [debug] 12993#0: *2 http script copy: "Connection: close " 2014/02/18 15:58:57 [debug] 12993#0: *2 http script copy: "" 2014/02/18 15:58:57 [debug] 12993#0: *2 http script copy: "" 2014/02/18 15:58:57 [debug] 12993#0: *2 http proxy header: "user-agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:27.0) Gecko/20100101 Firefox/27.0" 2014/02/18 15:58:57 [debug] 12993#0: *2 http proxy header: "cache-control: max-age=0" 2014/02/18 15:58:57 [debug] 12993#0: *2 http proxy header: "accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8" 2014/02/18 15:58:57 [debug] 12993#0: *2 http proxy header: "accept-language: de-de,de;q=0.8,en-us;q=0.5,en;q=0.3" 2014/02/18 15:58:57 [debug] 12993#0: *2 http proxy header: "cookie: cfid=b0fc4a14-0812-48b6-aea7-077c7b61cca7; cftoken=0; _ga=GA1.2.982493482.1392732645; JSESSIONID=5ln6ihdqossy18j3j9ouz680c" 2014/02/18 15:58:57 [debug] 12993#0: *2 http proxy header: "dnt: 1" 2014/02/18 15:58:57 [debug] 12993#0: *2 http proxy header: "GET /index.cfm HTTP/1.0 Host: www.example.org X-Forwarded-Host: www.example.org X-Forwarded-Server: www.example.org X-Forwarded-For: 192.168.76.46 X-Real-IP: 192.168.76.46 Connection: close user-agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:27.0) Gecko/20100101 Firefox/27.0 cache-control: max-age=0 accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8 accept-language: de-de,de;q=0.8,en-us;q=0.5,en;q=0.3 cookie: cfid=b0fc4a14-0812-48b6-aea7-077c7b61cca7; cftoken=0; _ga=GA1.2.982493482.1392732645; JSESSIONID=5ln6ihdqossy18j3j9ouz680c dnt: 1
" 2014/02/18 15:58:57 [debug] 12993#0: *2 http cleanup add: 0000000001D53950 2014/02/18 15:58:57 [debug] 12993#0: *2 get rr peer, try: 1 2014/02/18 15:58:57 [debug] 12993#0: *2 socket 17 2014/02/18 15:58:57 [debug] 12993#0: *2 epoll add connection: fd:17 ev:80002005 2014/02/18 15:58:57 [debug] 12993#0: *2 connect to 127.0.0.1:8888, fd:17 #3 2014/02/18 15:58:57 [debug] 12993#0: *2 http upstream connect: -2 2014/02/18 15:58:57 [debug] 12993#0: *2 posix_memalign: 0000000001CD8B00:128 @16 2014/02/18 15:58:57 [debug] 12993#0: *2 event timer add: 17: 60000:1392735597388 2014/02/18 15:58:57 [debug] 12993#0: *2 http finalize request: -4, "/index.cfm?" a:1, c:3 2014/02/18 15:58:57 [debug] 12993#0: *2 http request count:3 blk:0 2014/02/18 15:58:57 [debug] 12993#0: *2 http finalize request: -4, "/index.cfm?" a:1, c:2 2014/02/18 15:58:57 [debug] 12993#0: *2 http request count:2 blk:0 2014/02/18 15:58:57 [debug] 12993#0: *2 spdy process frame head:80030009 f:0 l:8 2014/02/18 15:58:57 [debug] 12993#0: *2 spdy WINDOW_UPDATE sid:1 delta:268369920 2014/02/18 15:58:57 [debug] 12993#0: *2 event timer del: 15: 1392735717380 2014/02/18 15:58:57 [debug] 12993#0: *2 post event 00007F19756931B0 2014/02/18 15:58:57 [debug] 12993#0: *2 delete posted event 00007F19756931B0 2014/02/18 15:58:57 [debug] 12993#0: *2 http upstream request: "/index.cfm?" 2014/02/18 15:58:57 [debug] 12993#0: *2 http upstream send request handler 2014/02/18 15:58:57 [debug] 12993#0: *2 http upstream send request 2014/02/18 15:58:57 [debug] 12993#0: *2 chain writer buf fl:1 s:597 2014/02/18 15:58:57 [debug] 12993#0: *2 chain writer in: 0000000001D53988 2014/02/18 15:58:57 [debug] 12993#0: *2 writev: 597 2014/02/18 15:58:57 [debug] 12993#0: *2 chain writer out: 0000000000000000 2014/02/18 15:58:57 [debug] 12993#0: *2 event timer del: 17: 1392735597388 2014/02/18 15:58:57 [debug] 12993#0: *2 event timer add: 17: 900000:1392736437394 2014/02/18 15:59:01 [debug] 12993#0: *2 post event 00007F19759D41B0 2014/02/18 15:59:01 [debug] 12993#0: *2 post event 00007F19756931B0 2014/02/18 15:59:01 [debug] 12993#0: *2 delete posted event 00007F19756931B0 2014/02/18 15:59:01 [debug] 12993#0: *2 http upstream request: "/index.cfm?" 2014/02/18 15:59:01 [debug] 12993#0: *2 http upstream dummy handler 2014/02/18 15:59:01 [debug] 12993#0: *2 delete posted event 00007F19759D41B0 2014/02/18 15:59:01 [debug] 12993#0: *2 http upstream request: "/index.cfm?" 2014/02/18 15:59:01 [debug] 12993#0: *2 http upstream process header 2014/02/18 15:59:01 [debug] 12993#0: *2 malloc: 0000000001D651A0:4096 2014/02/18 15:59:01 [debug] 12993#0: *2 recv: fd:17 235 of 4096 2014/02/18 15:59:01 [debug] 12993#0: *2 http proxy status 200 "200 OK" 2014/02/18 15:59:01 [debug] 12993#0: *2 http proxy header: "Server: Apache-Coyote/1.1" 2014/02/18 15:59:01 [debug] 12993#0: *2 http proxy header: "Set-Cookie: JSESSIONID=396DC49FA6AF6BE7BDB1B46A00612E34; Path=/; HttpOnly" 2014/02/18 15:59:01 [debug] 12993#0: *2 http proxy header: "Content-Type: text/html;charset=UTF-8" 2014/02/18 15:59:01 [debug] 12993#0: *2 http proxy header: "Content-Length: 0" 2014/02/18 15:59:01 [debug] 12993#0: *2 http proxy header: "Date: Tue, 18 Feb 2014 14:59:01 GMT" 2014/02/18 15:59:01 [debug] 12993#0: *2 http proxy header: "Connection: close" 2014/02/18 15:59:01 [debug] 12993#0: *2 http proxy header done 2014/02/18 15:59:01 [debug] 12993#0: *2 xslt filter header 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy header filter 2014/02/18 15:59:01 [debug] 12993#0: *2 malloc: 0000000001CDA270:306 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy deflate out: ni:0000000001CDA38F no:0000000001D646D3 ai:0 ao:36 rc:0 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy:1 create SYN_REPLY frame 0000000001D64708: len:307 2014/02/18 15:59:01 [debug] 12993#0: *2 http cleanup add: 0000000001D64748 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy frame out: 0000000001D64708 sid:1 prio:2 bl:1 len:307 2014/02/18 15:59:01 [debug] 12993#0: *2 malloc: 0000000001D661B0:16384 2014/02/18 15:59:01 [debug] 12993#0: *2 SSL buf copy: 315 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy:1 SYN_REPLY frame 0000000001D64708 was sent 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy frame sent: 0000000001D64708 sid:1 bl:1 len:307 2014/02/18 15:59:01 [debug] 12993#0: *2 http cacheable: 0 2014/02/18 15:59:01 [debug] 12993#0: *2 http proxy filter init s:200 h:0 c:0 l:0 2014/02/18 15:59:01 [debug] 12993#0: *2 http upstream process upstream 2014/02/18 15:59:01 [debug] 12993#0: *2 pipe read upstream: 1 2014/02/18 15:59:01 [debug] 12993#0: *2 pipe preread: 0 2014/02/18 15:59:01 [debug] 12993#0: *2 readv: 1:3861 2014/02/18 15:59:01 [debug] 12993#0: *2 readv() not ready (11: Resource temporarily unavailable) 2014/02/18 15:59:01 [debug] 12993#0: *2 pipe recv chain: -2 2014/02/18 15:59:01 [debug] 12993#0: *2 pipe buf free s:0 t:1 f:0 0000000001D651A0, pos 0000000001D6528B, size: 0 file: 0, size: 0 2014/02/18 15:59:01 [debug] 12993#0: *2 pipe length: 0 2014/02/18 15:59:01 [debug] 12993#0: *2 pipe write downstream: 1 2014/02/18 15:59:01 [debug] 12993#0: *2 pipe write downstream done 2014/02/18 15:59:01 [debug] 12993#0: *2 event timer del: 17: 1392736437394 2014/02/18 15:59:01 [debug] 12993#0: *2 event timer add: 17: 900000:1392736441385 2014/02/18 15:59:01 [debug] 12993#0: *2 http upstream exit: 0000000000000000 2014/02/18 15:59:01 [debug] 12993#0: *2 finalize http upstream request: 0 2014/02/18 15:59:01 [debug] 12993#0: *2 finalize http proxy request 2014/02/18 15:59:01 [debug] 12993#0: *2 free rr peer 1 0 2014/02/18 15:59:01 [debug] 12993#0: *2 close http upstream connection: 17 2014/02/18 15:59:01 [debug] 12993#0: *2 free: 0000000001CD8B00, unused: 48 2014/02/18 15:59:01 [debug] 12993#0: *2 event timer del: 17: 1392736441385 2014/02/18 15:59:01 [debug] 12993#0: *2 reusable connection: 0 2014/02/18 15:59:01 [debug] 12993#0: *2 http upstream temp fd: -1 2014/02/18 15:59:01 [debug] 12993#0: *2 http output filter "/index.cfm?" 2014/02/18 15:59:01 [debug] 12993#0: *2 http copy filter: "/index.cfm?" 2014/02/18 15:59:01 [debug] 12993#0: *2 image filter 2014/02/18 15:59:01 [debug] 12993#0: *2 xslt filter body 2014/02/18 15:59:01 [debug] 12993#0: *2 http postpone filter "/index.cfm?" 00007FFF0EE2CD10 2014/02/18 15:59:01 [debug] 12993#0: *2 write new buf t:0 f:0 0000000000000000, pos 0000000000000000, size: 0 file: 0, size: 0 2014/02/18 15:59:01 [debug] 12993#0: *2 http write filter: l:1 f:0 s:0 2014/02/18 15:59:01 [debug] 12993#0: *2 http write filter limit 0 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy:1 create DATA frame 0000000001D64708: len:0 flags:1 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy frame out: 0000000001D64708 sid:1 prio:2 bl:0 len:0 2014/02/18 15:59:01 [debug] 12993#0: *2 SSL buf copy: 8 2014/02/18 15:59:01 [debug] 12993#0: *2 SSL to write: 323 2014/02/18 15:59:01 [debug] 12993#0: *2 SSL_write: 323 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy:1 DATA frame 0000000001D64708 was sent 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy frame sent: 0000000001D64708 sid:1 bl:0 len:0 2014/02/18 15:59:01 [debug] 12993#0: *2 http write filter 0000000000000000 2014/02/18 15:59:01 [debug] 12993#0: *2 http copy filter: 0 "/index.cfm?" 2014/02/18 15:59:01 [debug] 12993#0: *2 http finalize request: 0, "/index.cfm?" a:1, c:1 2014/02/18 15:59:01 [debug] 12993#0: *2 http request count:1 blk:0 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy close stream 1, queued 0, processing 1 2014/02/18 15:59:01 [debug] 12993#0: *2 http close request 2014/02/18 15:59:01 [debug] 12993#0: *2 http log handler 2014/02/18 15:59:01 [debug] 12993#0: *2 run cleanup: 0000000001D531D0 2014/02/18 15:59:01 [debug] 12993#0: *2 close cached open file: /usr/share/nginx/html/example.org/index.cfm, fd:16, c:0, u:1, 0 2014/02/18 15:59:01 [debug] 12993#0: *2 free: 0000000001D651A0 2014/02/18 15:59:01 [debug] 12993#0: *2 free: 0000000001D51B00, unused: 4 2014/02/18 15:59:01 [debug] 12993#0: *2 free: 0000000001D52B10, unused: 0 2014/02/18 15:59:01 [debug] 12993#0: *2 free: 0000000001D64190, unused: 2048 2014/02/18 15:59:01 [debug] 12993#0: *2 post event 00007F19759D4148 2014/02/18 15:59:01 [debug] 12993#0: *2 delete posted event 00007F19759D4148 2014/02/18 15:59:01 [debug] 12993#0: *2 free: 0000000001D50AF0, unused: 3272 2014/02/18 15:59:01 [debug] 12993#0: *2 free: 0000000001D661B0 2014/02/18 15:59:01 [debug] 12993#0: *2 reusable connection: 1 2014/02/18 15:59:01 [debug] 12993#0: *2 event timer add: 15: 180000:1392735721385 2014/02/18 15:59:01 [debug] 12993#0: *2 post event 00007F19759D4148 2014/02/18 15:59:01 [debug] 12993#0: *2 delete posted event 00007F19759D4148 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy keepalive handler 2014/02/18 15:59:01 [debug] 12993#0: *2 reusable connection: 0 2014/02/18 15:59:01 [debug] 12993#0: *2 posix_memalign: 0000000001D50AF0:4096 @16 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy read handler 2014/02/18 15:59:01 [debug] 12993#0: *2 SSL_read: 550 2014/02/18 15:59:01 [debug] 12993#0: *2 SSL_read: -1 2014/02/18 15:59:01 [debug] 12993#0: *2 SSL_get_error: 2 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy process frame head:80030001 f:1 l:526 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy SYN_STREAM frame sid:3 prio:3 2014/02/18 15:59:01 [debug] 12993#0: *2 posix_memalign: 0000000001D51B00:4096 @16 2014/02/18 15:59:01 [debug] 12993#0: *2 posix_memalign: 0000000001D52B10:4096 @16 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy process HEADERS 516 of 516 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy inflate out: ni:00007F1975652226 no:0000000001D52D2A ai:0 ao:517 rc:0 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy HEADERS block consists of 10 entries 2014/02/18 15:59:01 [debug] 12993#0: *2 http uri: "/favicon.ico" 2014/02/18 15:59:01 [debug] 12993#0: *2 http args: "" 2014/02/18 15:59:01 [debug] 12993#0: *2 http exten: "ico" 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy http request line: "GET /favicon.ico HTTP/1.1" 2014/02/18 15:59:01 [debug] 12993#0: *2 http header: "host: www.example.org" 2014/02/18 15:59:01 [debug] 12993#0: *2 http header: "user-agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:27.0) Gecko/20100101 Firefox/27.0" 2014/02/18 15:59:01 [debug] 12993#0: *2 http header: "accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8" 2014/02/18 15:59:01 [debug] 12993#0: *2 http header: "accept-language: de-de,de;q=0.8,en-us;q=0.5,en;q=0.3" 2014/02/18 15:59:01 [debug] 12993#0: *2 http header: "cookie: cfid=b0fc4a14-0812-48b6-aea7-077c7b61cca7; cftoken=0; _ga=GA1.2.982493482.1392732645; JSESSIONID=396DC49FA6AF6BE7BDB1B46A00612E34" 2014/02/18 15:59:01 [debug] 12993#0: *2 http header: "dnt: 1" 2014/02/18 15:59:01 [debug] 12993#0: *2 generic phase: 0 2014/02/18 15:59:01 [debug] 12993#0: *2 rewrite phase: 1 2014/02/18 15:59:01 [debug] 12993#0: *2 http script regex: "^/\+" 2014/02/18 15:59:01 [notice] 12993#0: *2 "^/\+" does not match "/favicon.ico", client: 192.168.76.46, server: www.example.org, request: "GET /favicon.ico HTTP/1.1", host: "www.example.org" 2014/02/18 15:59:01 [debug] 12993#0: *2 http script var 2014/02/18 15:59:01 [debug] 12993#0: *2 http script var: "GET" 2014/02/18 15:59:01 [debug] 12993#0: *2 http script regex: "^(GET|HEAD|POST)$" 2014/02/18 15:59:01 [notice] 12993#0: *2 "^(GET|HEAD|POST)$" matches "GET", client: 192.168.76.46, server: www.example.org, request: "GET /favicon.ico HTTP/1.1", host: "www.example.org" 2014/02/18 15:59:01 [debug] 12993#0: *2 http script if 2014/02/18 15:59:01 [debug] 12993#0: *2 http script if: false 2014/02/18 15:59:01 [debug] 12993#0: *2 test location: "/" 2014/02/18 15:59:01 [debug] 12993#0: *2 test location: "core/" 2014/02/18 15:59:01 [debug] 12993#0: *2 test location: "includes/" 2014/02/18 15:59:01 [debug] 12993#0: *2 test location: "favicon.ico" 2014/02/18 15:59:01 [debug] 12993#0: *2 using configuration "=/favicon.ico" 2014/02/18 15:59:01 [debug] 12993#0: *2 http cl:-1 max:1048576 2014/02/18 15:59:01 [debug] 12993#0: *2 rewrite phase: 3 2014/02/18 15:59:01 [debug] 12993#0: *2 post rewrite phase: 4 2014/02/18 15:59:01 [debug] 12993#0: *2 generic phase: 5 2014/02/18 15:59:01 [debug] 12993#0: *2 generic phase: 6 2014/02/18 15:59:01 [debug] 12993#0: *2 generic phase: 7 2014/02/18 15:59:01 [debug] 12993#0: *2 generic phase: 8 2014/02/18 15:59:01 [debug] 12993#0: *2 access phase: 9 2014/02/18 15:59:01 [debug] 12993#0: *2 access phase: 10 2014/02/18 15:59:01 [debug] 12993#0: *2 post access phase: 11 2014/02/18 15:59:01 [debug] 12993#0: *2 try files phase: 12 2014/02/18 15:59:01 [debug] 12993#0: *2 content phase: 13 2014/02/18 15:59:01 [debug] 12993#0: *2 content phase: 14 2014/02/18 15:59:01 [debug] 12993#0: *2 content phase: 15 2014/02/18 15:59:01 [debug] 12993#0: *2 content phase: 16 2014/02/18 15:59:01 [debug] 12993#0: *2 content phase: 17 2014/02/18 15:59:01 [debug] 12993#0: *2 content phase: 18 2014/02/18 15:59:01 [debug] 12993#0: *2 http filename: "/usr/share/nginx/html/example.org/favicon.ico" 2014/02/18 15:59:01 [debug] 12993#0: *2 add cleanup: 0000000001D52A68 2014/02/18 15:59:01 [debug] 12993#0: *2 malloc: 0000000001CDC1D0:144 2014/02/18 15:59:01 [debug] 12993#0: *2 malloc: 0000000001CBBE20:53 2014/02/18 15:59:01 [debug] 12993#0: *2 cached open file: /usr/share/nginx/html/example.org/favicon.ico, fd:16, c:1, e:0, u:1 2014/02/18 15:59:01 [debug] 12993#0: *2 http static fd: 16 2014/02/18 15:59:01 [debug] 12993#0: *2 xslt filter header 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy header filter 2014/02/18 15:59:01 [debug] 12993#0: *2 malloc: 0000000001CDA270:315 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy deflate out: ni:0000000001CDA39B no:0000000001D53451 ai:0 ao:44 rc:0 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy:3 create SYN_REPLY frame 0000000001D53480: len:313 2014/02/18 15:59:01 [debug] 12993#0: *2 http cleanup add: 0000000001D52AE8 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy frame out: 0000000001D53480 sid:3 prio:3 bl:1 len:313 2014/02/18 15:59:01 [debug] 12993#0: *2 malloc: 0000000001D64190:16384 2014/02/18 15:59:01 [debug] 12993#0: *2 SSL buf copy: 321 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy:3 SYN_REPLY frame 0000000001D53480 was sent 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy frame sent: 0000000001D53480 sid:3 bl:1 len:313 2014/02/18 15:59:01 [debug] 12993#0: *2 http output filter "/favicon.ico?" 2014/02/18 15:59:01 [debug] 12993#0: *2 http copy filter: "/favicon.ico?" 2014/02/18 15:59:01 [debug] 12993#0: *2 posix_memalign: 0000000001D681A0:4096 @16 2014/02/18 15:59:01 [debug] 12993#0: *2 read: 16, 0000000001D681C0, 3262, 0 2014/02/18 15:59:01 [debug] 12993#0: *2 image filter 2014/02/18 15:59:01 [debug] 12993#0: *2 xslt filter body 2014/02/18 15:59:01 [debug] 12993#0: *2 http postpone filter "/favicon.ico?" 0000000001D53580 2014/02/18 15:59:01 [debug] 12993#0: *2 write new buf t:1 f:1 0000000001D681C0, pos 0000000001D681C0, size: 3262 file: 0, size: 3262 2014/02/18 15:59:01 [debug] 12993#0: *2 http write filter: l:1 f:0 s:3262 2014/02/18 15:59:01 [debug] 12993#0: *2 http write filter limit 0 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy:3 create DATA frame 0000000001D53480: len:3262 flags:1 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy frame out: 0000000001D53480 sid:3 prio:3 bl:0 len:3262 2014/02/18 15:59:01 [debug] 12993#0: *2 SSL buf copy: 8 2014/02/18 15:59:01 [debug] 12993#0: *2 SSL buf copy: 3262 2014/02/18 15:59:01 [debug] 12993#0: *2 SSL to write: 3591 2014/02/18 15:59:01 [debug] 12993#0: *2 SSL_write: 3591 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy:3 DATA frame 0000000001D53480 was sent 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy frame sent: 0000000001D53480 sid:3 bl:0 len:3262 2014/02/18 15:59:01 [debug] 12993#0: *2 http write filter 0000000000000000 2014/02/18 15:59:01 [debug] 12993#0: *2 http copy filter: 0 "/favicon.ico?" 2014/02/18 15:59:01 [debug] 12993#0: *2 http finalize request: 0, "/favicon.ico?" a:1, c:1 2014/02/18 15:59:01 [debug] 12993#0: *2 http request count:1 blk:0 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy close stream 3, queued 0, processing 1 2014/02/18 15:59:01 [debug] 12993#0: *2 http close request 2014/02/18 15:59:01 [debug] 12993#0: *2 http log handler 2014/02/18 15:59:01 [debug] 12993#0: *2 run cleanup: 0000000001D52A68 2014/02/18 15:59:01 [debug] 12993#0: *2 close cached open file: /usr/share/nginx/html/example.org/favicon.ico, fd:16, c:0, u:1, 0 2014/02/18 15:59:01 [debug] 12993#0: *2 free: 0000000001D51B00, unused: 0 2014/02/18 15:59:01 [debug] 12993#0: *2 free: 0000000001D52B10, unused: 1272 2014/02/18 15:59:01 [debug] 12993#0: *2 free: 0000000001D681A0, unused: 802 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy process frame head:80030009 f:0 l:8 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy WINDOW_UPDATE sid:3 delta:268369920 2014/02/18 15:59:01 [info] 12993#0: *2 client sent WINDOW_UPDATE frame for unknown stream 3 while processing SPDY, client: 192.168.76.46, server: 192.168.89.175:443 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy write RST_STREAM sid:3 st:2 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy frame out: 0000000001D50E28 sid:0 prio:7 bl:0 len:8 2014/02/18 15:59:01 [debug] 12993#0: *2 SSL buf copy: 16 2014/02/18 15:59:01 [debug] 12993#0: *2 SSL to write: 16 2014/02/18 15:59:01 [debug] 12993#0: *2 SSL_write: 16 2014/02/18 15:59:01 [debug] 12993#0: *2 spdy frame sent: 0000000001D50E28 sid:0 bl:0 len:8 2014/02/18 15:59:01 [debug] 12993#0: *2 free: 0000000001D50AF0, unused: 3096 2014/02/18 15:59:01 [debug] 12993#0: *2 free: 0000000001D64190 2014/02/18 15:59:01 [debug] 12993#0: *2 reusable connection: 1 2014/02/18 15:59:01 [debug] 12993#0: *2 event timer: 15, old: 1392735721385, new: 1392735721410 Posted at Nginx Forum: http://forum.nginx.org/read.php?2,247692,247697#msg-247697 _______________________________________________ nginx mailing list nginx@nginx.org http://mailman.nginx.org/mailman/listinfo/nginx