Issue with spdy and proxy_pass

[p.heppler]

I just created a new log. This is from nginx restart to first request:

2014/02/18 15:45:56 [debug] 12839#0: epoll add event: fd:9 op:1 ev:00002001
2014/02/18 15:46:12 [debug] 12839#0: post event 00007F29CC9D1078
2014/02/18 15:46:12 [debug] 12839#0: delete posted event 00007F29CC9D1078
2014/02/18 15:46:12 [debug] 12839#0: accept on 192.168.89.175:443, ready: 1
2014/02/18 15:46:12 [debug] 12839#0: posix_memalign: 0000000002547890:256
@16
2014/02/18 15:46:12 [debug] 12839#0: *1 accept: 192.168.76.46 fd:15
2014/02/18 15:46:12 [debug] 12839#0: posix_memalign: 0000000002547330:256
@16
2014/02/18 15:46:12 [debug] 12839#0: *1 event timer add: 15:
60000:1392734832664
2014/02/18 15:46:12 [debug] 12839#0: *1 reusable connection: 1
2014/02/18 15:46:12 [debug] 12839#0: *1 epoll add event: fd:15 op:1
ev:80002001
2014/02/18 15:46:12 [debug] 12839#0: accept() not ready (11: Resource
temporarily unavailable)
2014/02/18 15:46:12 [debug] 12839#0: *1 post event 00007F29CC9D1148
2014/02/18 15:46:12 [debug] 12839#0: *1 delete posted event
00007F29CC9D1148
2014/02/18 15:46:12 [debug] 12839#0: *1 http check ssl handshake
2014/02/18 15:46:12 [debug] 12839#0: *1 http recv(): 1
2014/02/18 15:46:12 [debug] 12839#0: *1 https ssl handshake: 0x16
2014/02/18 15:46:12 [debug] 12839#0: *1 SSL server name: "www.example.org"
2014/02/18 15:46:12 [debug] 12839#0: *1 SSL_do_handshake: 0
2014/02/18 15:46:12 [debug] 12839#0: *1 SSL_get_error: 5
2014/02/18 15:46:12 [info] 12839#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:46:12 [debug] 12839#0: *1 close http connection: 15
2014/02/18 15:46:12 [debug] 12839#0: *1 SSL_shutdown: 1
2014/02/18 15:46:12 [debug] 12839#0: *1 event timer del: 15: 1392734832664
2014/02/18 15:46:12 [debug] 12839#0: *1 reusable connection: 0
2014/02/18 15:46:12 [debug] 12839#0: *1 free: 0000000002547890, unused: 16
2014/02/18 15:46:12 [debug] 12839#0: *1 free: 0000000002547330, unused: 114
2014/02/18 15:46:12 [debug] 12839#0: post event 00007F29CC9D1078
2014/02/18 15:46:12 [debug] 12839#0: delete posted event 00007F29CC9D1078
2014/02/18 15:46:12 [debug] 12839#0: accept on 192.168.89.175:443, ready: 1
2014/02/18 15:46:12 [debug] 12839#0: posix_memalign: 000000000252BF80:256
@16
2014/02/18 15:46:12 [debug] 12839#0: *2 accept: 192.168.76.46 fd:15
2014/02/18 15:46:12 [debug] 12839#0: posix_memalign: 0000000002547890:256
@16
2014/02/18 15:46:12 [debug] 12839#0: *2 event timer add: 15:
60000:1392734832672
2014/02/18 15:46:12 [debug] 12839#0: *2 reusable connection: 1
2014/02/18 15:46:12 [debug] 12839#0: *2 epoll add event: fd:15 op:1
ev:80002001
2014/02/18 15:46:12 [debug] 12839#0: accept() not ready (11: Resource
temporarily unavailable)
2014/02/18 15:46:12 [debug] 12839#0: *2 post event 00007F29CC9D1148
2014/02/18 15:46:12 [debug] 12839#0: *2 delete posted event
00007F29CC9D1148
2014/02/18 15:46:12 [debug] 12839#0: *2 http check ssl handshake
2014/02/18 15:46:12 [debug] 12839#0: *2 http recv(): 1
2014/02/18 15:46:12 [debug] 12839#0: *2 https ssl handshake: 0x16
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL server name: "www.example.org"
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL NPN advertised
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL_do_handshake: -1
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL_get_error: 2
2014/02/18 15:46:12 [debug] 12839#0: *2 reusable connection: 0
2014/02/18 15:46:12 [debug] 12839#0: *2 post event 00007F29CC9D1148
2014/02/18 15:46:12 [debug] 12839#0: *2 delete posted event
00007F29CC9D1148
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL handshake handler: 0
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL_do_handshake: 1
2014/02/18 15:46:12 [debug] 12839#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:46:12 [debug] 12839#0: *2 init spdy request
2014/02/18 15:46:12 [debug] 12839#0: *2 malloc: 00000000024B1AA0:424
2014/02/18 15:46:12 [debug] 12839#0: *2 malloc: 00000000025981A0:9552
2014/02/18 15:46:12 [debug] 12839#0: *2 malloc: 00000000024B5940:5928
2014/02/18 15:46:12 [debug] 12839#0: *2 malloc: 000000000252C290:4096
2014/02/18 15:46:12 [debug] 12839#0: *2 malloc: 000000000259A700:4096
2014/02/18 15:46:12 [debug] 12839#0: *2 malloc: 00000000025A1AD0:4096
2014/02/18 15:46:12 [debug] 12839#0: *2 malloc: 00000000025A2AE0:4096
2014/02/18 15:46:12 [debug] 12839#0: *2 posix_memalign:
00000000025A3AF0:4096 @16
2014/02/18 15:46:12 [debug] 12839#0: *2 posix_memalign: 000000000252D2A0:256
@16
2014/02/18 15:46:12 [debug] 12839#0: *2 add cleanup: 000000000252D2C0
2014/02/18 15:46:12 [debug] 12839#0: *2 spdy create SETTINGS frame
2014/02/18 15:46:12 [debug] 12839#0: *2 spdy write WINDOW_UPDATE sid:0
delta:2147418111
2014/02/18 15:46:12 [debug] 12839#0: *2 spdy read handler
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL_read: -1
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL_get_error: 2
2014/02/18 15:46:12 [debug] 12839#0: *2 spdy frame out: 00000000025A3D00
sid:0 prio:0 bl:0 len:8
2014/02/18 15:46:12 [debug] 12839#0: *2 spdy frame out: 00000000025A3C40
sid:0 prio:0 bl:0 len:20
2014/02/18 15:46:12 [debug] 12839#0: *2 malloc: 00000000025AF180:16384
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL buf copy: 28
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL buf copy: 16
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL to write: 44
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL_write: 44
2014/02/18 15:46:12 [debug] 12839#0: *2 spdy frame sent: 00000000025A3C40
sid:0 bl:0 len:20
2014/02/18 15:46:12 [debug] 12839#0: *2 spdy frame sent: 00000000025A3D00
sid:0 bl:0 len:8
2014/02/18 15:46:12 [debug] 12839#0: *2 free: 00000000025A3AF0, unused:
3392
2014/02/18 15:46:12 [debug] 12839#0: *2 free: 00000000025AF180
2014/02/18 15:46:12 [debug] 12839#0: *2 reusable connection: 1
2014/02/18 15:46:12 [debug] 12839#0: *2 event timer del: 15: 1392734832672
2014/02/18 15:46:12 [debug] 12839#0: *2 event timer add: 15:
180000:1392734952688
2014/02/18 15:46:12 [debug] 12839#0: *2 post event 00007F29CC9D1148
2014/02/18 15:46:12 [debug] 12839#0: *2 delete posted event
00007F29CC9D1148
2014/02/18 15:46:12 [debug] 12839#0: *2 spdy keepalive handler
2014/02/18 15:46:12 [debug] 12839#0: *2 reusable connection: 0
2014/02/18 15:46:12 [debug] 12839#0: *2 posix_memalign:
00000000025A3AF0:4096 @16
2014/02/18 15:46:12 [debug] 12839#0: *2 spdy read handler
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL_read: 36
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL_read: -1
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL_get_error: 2
2014/02/18 15:46:12 [debug] 12839#0: *2 spdy process frame head:80030004 f:0
l:12
2014/02/18 15:46:12 [debug] 12839#0: *2 spdy SETTINGS frame consists of 1
entries
2014/02/18 15:46:12 [debug] 12839#0: *2 spdy SETTINGS entry fl:0 id:7
val:65536
2014/02/18 15:46:12 [debug] 12839#0: *2 spdy process frame head:80030009 f:0
l:8
2014/02/18 15:46:12 [debug] 12839#0: *2 spdy WINDOW_UPDATE sid:0
delta:268369920
2014/02/18 15:46:12 [debug] 12839#0: *2 free: 00000000025A3AF0, unused:
3760
2014/02/18 15:46:12 [debug] 12839#0: *2 reusable connection: 1
2014/02/18 15:46:12 [debug] 12839#0: *2 event timer: 15, old: 1392734952688,
new: 1392734952690
2014/02/18 15:46:12 [debug] 12839#0: *2 post event 00007F29CC9D1148
2014/02/18 15:46:12 [debug] 12839#0: *2 delete posted event
00007F29CC9D1148
2014/02/18 15:46:12 [debug] 12839#0: *2 spdy keepalive handler
2014/02/18 15:46:12 [debug] 12839#0: *2 reusable connection: 0
2014/02/18 15:46:12 [debug] 12839#0: *2 posix_memalign:
00000000025A3AF0:4096 @16
2014/02/18 15:46:12 [debug] 12839#0: *2 spdy read handler
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL_read: 568
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL_read: -1
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL_get_error: 2
2014/02/18 15:46:12 [debug] 12839#0: *2 spdy process frame head:80030001 f:1
l:544
2014/02/18 15:46:12 [debug] 12839#0: *2 spdy SYN_STREAM frame sid:1 prio:2
2014/02/18 15:46:12 [debug] 12839#0: *2 posix_memalign:
00000000025A4B00:4096 @16
2014/02/18 15:46:12 [debug] 12839#0: *2 posix_memalign:
00000000025A5B10:4096 @16
2014/02/18 15:46:12 [debug] 12839#0: *2 spdy process HEADERS 534 of 534
2014/02/18 15:46:12 [debug] 12839#0: *2 malloc: 00000000025AF180:32768
2014/02/18 15:46:12 [debug] 12839#0: *2 spdy inflateSetDictionary(): 0
2014/02/18 15:46:12 [debug] 12839#0: *2 spdy inflate out:
ni:00007F29CC64F238 no:00000000025A5D36 ai:0 ao:505 rc:0
2014/02/18 15:46:12 [debug] 12839#0: *2 spdy HEADERS block consists of 11
entries
2014/02/18 15:46:12 [debug] 12839#0: *2 http uri: "/"
2014/02/18 15:46:12 [debug] 12839#0: *2 http args: ""
2014/02/18 15:46:12 [debug] 12839#0: *2 http exten: ""
2014/02/18 15:46:12 [debug] 12839#0: *2 spdy http request line: "GET /
HTTP/1.1"
2014/02/18 15:46:12 [debug] 12839#0: *2 http header: "host:
www.example.org"
2014/02/18 15:46:12 [debug] 12839#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:46:12 [debug] 12839#0: *2 http header: "cache-control:
max-age=0"
2014/02/18 15:46:12 [debug] 12839#0: *2 http header: "accept:
text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8"
2014/02/18 15:46:12 [debug] 12839#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:46:12 [debug] 12839#0: *2 http header: "cookie:
cfid=b0fc4a14-0812-48b6-aea7-077c7b61cca7; cftoken=0;
_ga=GA1.2.982493482.1392732645; JSESSIONID=5ln6ihdqossy18j3j9ouz680c"
2014/02/18 15:46:12 [debug] 12839#0: *2 http header: "dnt: 1"
2014/02/18 15:46:12 [debug] 12839#0: *2 generic phase: 0
2014/02/18 15:46:12 [debug] 12839#0: *2 rewrite phase: 1
2014/02/18 15:46:12 [debug] 12839#0: *2 http script regex: "^/\+"
2014/02/18 15:46:12 [notice] 12839#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:46:12 [debug] 12839#0: *2 http script var
2014/02/18 15:46:12 [debug] 12839#0: *2 http script var: "GET"
2014/02/18 15:46:12 [debug] 12839#0: *2 http script regex:
"^(GET|HEAD|POST)$"
2014/02/18 15:46:12 [notice] 12839#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:46:12 [debug] 12839#0: *2 http script if
2014/02/18 15:46:12 [debug] 12839#0: *2 http script if: false
2014/02/18 15:46:12 [debug] 12839#0: *2 test location: "/"
2014/02/18 15:46:12 [debug] 12839#0: *2 test location: ~ "\.(?:png|jpe?g)$"
2014/02/18 15:46:12 [debug] 12839#0: *2 test location: ~ "\.php$"
2014/02/18 15:46:12 [debug] 12839#0: *2 test location: ~
"\.(cfm|cfml|cfc|jsp|cfr)(.*)$"
2014/02/18 15:46:12 [debug] 12839#0: *2 test location: ~ "/\."
2014/02/18 15:46:12 [debug] 12839#0: *2 test location: ~
"\.(?:eot|ttf|woff|otf|svg)$"
2014/02/18 15:46:12 [debug] 12839#0: *2 test location: ~
"\.(?:css|js|png|jpe?g|ico|gif)$"
2014/02/18 15:46:12 [debug] 12839#0: *2 test location: ~
"\.(aspx|asp|jsp|cgi)$"
2014/02/18 15:46:12 [debug] 12839#0: *2 using configuration "/"
2014/02/18 15:46:12 [debug] 12839#0: *2 http cl:-1 max:1048576
2014/02/18 15:46:12 [debug] 12839#0: *2 rewrite phase: 3
2014/02/18 15:46:12 [debug] 12839#0: *2 post rewrite phase: 4
2014/02/18 15:46:12 [debug] 12839#0: *2 generic phase: 5
2014/02/18 15:46:12 [debug] 12839#0: *2 generic phase: 6
2014/02/18 15:46:12 [debug] 12839#0: *2 generic phase: 7
2014/02/18 15:46:12 [debug] 12839#0: *2 generic phase: 8
2014/02/18 15:46:12 [debug] 12839#0: *2 access phase: 9
2014/02/18 15:46:12 [debug] 12839#0: *2 access phase: 10
2014/02/18 15:46:12 [debug] 12839#0: *2 post access phase: 11
2014/02/18 15:46:12 [debug] 12839#0: *2 try files phase: 12
2014/02/18 15:46:12 [debug] 12839#0: *2 http script var: "/"
2014/02/18 15:46:12 [debug] 12839#0: *2 trying to use file: "/"
"/usr/share/nginx/html/example.org/"
2014/02/18 15:46:12 [debug] 12839#0: *2 add cleanup: 00000000025A5A58
2014/02/18 15:46:12 [debug] 12839#0: *2 malloc: 0000000002547440:144
2014/02/18 15:46:12 [debug] 12839#0: *2 malloc: 000000000252BDD0:42
2014/02/18 15:46:12 [debug] 12839#0: *2 cached open file:
/usr/share/nginx/html/example.org/, fd:-1, c:0, e:0, u:1
2014/02/18 15:46:12 [debug] 12839#0: *2 http script var: "/"
2014/02/18 15:46:12 [debug] 12839#0: *2 trying to use dir: "/"
"/usr/share/nginx/html/example.org/"
2014/02/18 15:46:12 [debug] 12839#0: *2 add cleanup: 00000000025A5A90
2014/02/18 15:46:12 [debug] 12839#0: *2 cached open file:
/usr/share/nginx/html/example.org/, fd:-1, c:0, e:0, u:2
2014/02/18 15:46:12 [debug] 12839#0: *2 try file uri: "/"
2014/02/18 15:46:12 [debug] 12839#0: *2 content phase: 13
2014/02/18 15:46:12 [debug] 12839#0: *2 content phase: 14
2014/02/18 15:46:12 [debug] 12839#0: *2 open index
"/usr/share/nginx/html/example.org/index.cfm"
2014/02/18 15:46:12 [debug] 12839#0: *2 add cleanup: 00000000025A61D0
2014/02/18 15:46:12 [debug] 12839#0: *2 malloc: 0000000002547C30:144
2014/02/18 15:46:12 [debug] 12839#0: *2 malloc: 00000000025476D0:51
2014/02/18 15:46:12 [debug] 12839#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:46:12 [debug] 12839#0: *2 internal redirect: "/index.cfm?"
2014/02/18 15:46:12 [debug] 12839#0: *2 rewrite phase: 1
2014/02/18 15:46:12 [debug] 12839#0: *2 http script regex: "^/\+"
2014/02/18 15:46:12 [notice] 12839#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:46:12 [debug] 12839#0: *2 http script var
2014/02/18 15:46:12 [debug] 12839#0: *2 http script var: "GET"
2014/02/18 15:46:12 [debug] 12839#0: *2 http script regex:
"^(GET|HEAD|POST)$"
2014/02/18 15:46:12 [notice] 12839#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:46:12 [debug] 12839#0: *2 http script if
2014/02/18 15:46:12 [debug] 12839#0: *2 http script if: false
2014/02/18 15:46:12 [debug] 12839#0: *2 test location: "/"
2014/02/18 15:46:12 [debug] 12839#0: *2 test location: "core/"
2014/02/18 15:46:12 [debug] 12839#0: *2 test location: "includes/"
2014/02/18 15:46:12 [debug] 12839#0: *2 test location: "templates/"
2014/02/18 15:46:12 [debug] 12839#0: *2 test location: "robots.txt"
2014/02/18 15:46:12 [debug] 12839#0: *2 test location: ~ "\.(?:png|jpe?g)$"
2014/02/18 15:46:12 [debug] 12839#0: *2 test location: ~ "\.php$"
2014/02/18 15:46:12 [debug] 12839#0: *2 test location: ~
"\.(cfm|cfml|cfc|jsp|cfr)(.*)$"
2014/02/18 15:46:12 [debug] 12839#0: *2 using configuration
"\.(cfm|cfml|cfc|jsp|cfr)(.*)$"
2014/02/18 15:46:12 [debug] 12839#0: *2 http cl:-1 max:1048576
2014/02/18 15:46:12 [debug] 12839#0: *2 rewrite phase: 3
2014/02/18 15:46:12 [debug] 12839#0: *2 post rewrite phase: 4
2014/02/18 15:46:12 [debug] 12839#0: *2 generic phase: 5
2014/02/18 15:46:12 [debug] 12839#0: *2 generic phase: 6
2014/02/18 15:46:12 [debug] 12839#0: *2 generic phase: 7
2014/02/18 15:46:12 [debug] 12839#0: *2 generic phase: 8
2014/02/18 15:46:12 [debug] 12839#0: *2 access phase: 9
2014/02/18 15:46:12 [debug] 12839#0: *2 access phase: 10
2014/02/18 15:46:12 [debug] 12839#0: *2 post access phase: 11
2014/02/18 15:46:12 [debug] 12839#0: *2 try files phase: 12
2014/02/18 15:46:12 [debug] 12839#0: *2 spdy read request body
2014/02/18 15:46:12 [debug] 12839#0: *2 http init upstream, client timer: 0
2014/02/18 15:46:12 [debug] 12839#0: *2 posix_memalign:
00000000025B7190:4096 @16
2014/02/18 15:46:12 [debug] 12839#0: *2 http script copy: "Host: "
2014/02/18 15:46:12 [debug] 12839#0: *2 http script var: "www.example.org"
2014/02/18 15:46:12 [debug] 12839#0: *2 http script copy: "
"
2014/02/18 15:46:12 [debug] 12839#0: *2 http script copy: "X-Forwarded-Host:
"
2014/02/18 15:46:12 [debug] 12839#0: *2 http script var: "www.example.org"
2014/02/18 15:46:12 [debug] 12839#0: *2 http script copy: "
"
2014/02/18 15:46:12 [debug] 12839#0: *2 http script copy:
"X-Forwarded-Server: "
2014/02/18 15:46:12 [debug] 12839#0: *2 http script var: "www.example.org"
2014/02/18 15:46:12 [debug] 12839#0: *2 http script copy: "
"
2014/02/18 15:46:12 [debug] 12839#0: *2 http script copy: "X-Forwarded-For:
"
2014/02/18 15:46:12 [debug] 12839#0: *2 http script var: "192.168.76.46"
2014/02/18 15:46:12 [debug] 12839#0: *2 http script copy: "
"
2014/02/18 15:46:12 [debug] 12839#0: *2 http script copy: "X-Real-IP: "
2014/02/18 15:46:12 [debug] 12839#0: *2 http script var: "192.168.76.46"
2014/02/18 15:46:12 [debug] 12839#0: *2 http script copy: "
"
2014/02/18 15:46:12 [debug] 12839#0: *2 http script copy: "Connection:
close
"
2014/02/18 15:46:12 [debug] 12839#0: *2 http script copy: ""
2014/02/18 15:46:12 [debug] 12839#0: *2 http script copy: ""
2014/02/18 15:46:12 [debug] 12839#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:46:12 [debug] 12839#0: *2 http proxy header: "cache-control:
max-age=0"
2014/02/18 15:46:12 [debug] 12839#0: *2 http proxy header: "accept:
text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8"
2014/02/18 15:46:12 [debug] 12839#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:46:12 [debug] 12839#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:46:12 [debug] 12839#0: *2 http proxy header: "dnt: 1"
2014/02/18 15:46:12 [debug] 12839#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:46:12 [debug] 12839#0: *2 http cleanup add: 00000000025A6950
2014/02/18 15:46:12 [debug] 12839#0: *2 get rr peer, try: 1
2014/02/18 15:46:12 [debug] 12839#0: *2 socket 17
2014/02/18 15:46:12 [debug] 12839#0: *2 epoll add connection: fd:17
ev:80002005
2014/02/18 15:46:12 [debug] 12839#0: *2 connect to 127.0.0.1:8443, fd:17 #3
2014/02/18 15:46:12 [debug] 12839#0: *2 http upstream connect: -2
2014/02/18 15:46:12 [debug] 12839#0: *2 posix_memalign: 000000000252BB20:128
@16
2014/02/18 15:46:12 [debug] 12839#0: *2 event timer add: 17:
60000:1392734832690
2014/02/18 15:46:12 [debug] 12839#0: *2 http finalize request: -4,
"/index.cfm?" a:1, c:3
2014/02/18 15:46:12 [debug] 12839#0: *2 http request count:3 blk:0
2014/02/18 15:46:12 [debug] 12839#0: *2 http finalize request: -4,
"/index.cfm?" a:1, c:2
2014/02/18 15:46:12 [debug] 12839#0: *2 http request count:2 blk:0
2014/02/18 15:46:12 [debug] 12839#0: *2 spdy process frame head:80030009 f:0
l:8
2014/02/18 15:46:12 [debug] 12839#0: *2 spdy WINDOW_UPDATE sid:1
delta:268369920
2014/02/18 15:46:12 [debug] 12839#0: *2 event timer del: 15: 1392734952688
2014/02/18 15:46:12 [debug] 12839#0: *2 post event 00007F29CC6901B0
2014/02/18 15:46:12 [debug] 12839#0: *2 delete posted event
00007F29CC6901B0
2014/02/18 15:46:12 [debug] 12839#0: *2 http upstream request:
"/index.cfm?"
2014/02/18 15:46:12 [debug] 12839#0: *2 http upstream send request handler
2014/02/18 15:46:12 [debug] 12839#0: *2 malloc: 00000000025328D0:64
2014/02/18 15:46:12 [debug] 12839#0: *2 set session: 0000000000000000:0
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL_do_handshake: -1
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL_get_error: 2
2014/02/18 15:46:12 [debug] 12839#0: *2 post event 00007F29CC9D11B0
2014/02/18 15:46:12 [debug] 12839#0: *2 post event 00007F29CC6901B0
2014/02/18 15:46:12 [debug] 12839#0: *2 delete posted event
00007F29CC6901B0
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL handshake handler: 1
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL_do_handshake: -1
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL_get_error: 2
2014/02/18 15:46:12 [debug] 12839#0: *2 delete posted event
00007F29CC9D11B0
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL handshake handler: 0
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL_do_handshake: -1
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL_get_error: 2
2014/02/18 15:46:12 [debug] 12839#0: *2 post event 00007F29CC9D11B0
2014/02/18 15:46:12 [debug] 12839#0: *2 post event 00007F29CC6901B0
2014/02/18 15:46:12 [debug] 12839#0: *2 delete posted event
00007F29CC6901B0
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL handshake handler: 1
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL_do_handshake: 1
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL: TLSv1.2, cipher:
"ECDHE-RSA-DES-CBC3-SHA SSLv3 Kx=ECDH Au=RSA Enc=3DES(168) Mac=SHA1"
2014/02/18 15:46:12 [debug] 12839#0: *2 save session: 000000000252D4A0:2
2014/02/18 15:46:12 [debug] 12839#0: *2 http upstream send request
2014/02/18 15:46:12 [debug] 12839#0: *2 chain writer buf fl:1 s:597
2014/02/18 15:46:12 [debug] 12839#0: *2 chain writer in: 00000000025A6988
2014/02/18 15:46:12 [debug] 12839#0: *2 malloc: 00000000025CBB30:80
2014/02/18 15:46:12 [debug] 12839#0: *2 malloc: 00000000025B81A0:16384
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL buf copy: 597
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL to write: 597
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL_write: 597
2014/02/18 15:46:12 [debug] 12839#0: *2 chain writer out: 0000000000000000
2014/02/18 15:46:12 [debug] 12839#0: *2 event timer del: 17: 1392734832690
2014/02/18 15:46:12 [debug] 12839#0: *2 event timer add: 17:
900000:1392735672713
2014/02/18 15:46:12 [debug] 12839#0: *2 http upstream process header
2014/02/18 15:46:12 [debug] 12839#0: *2 malloc: 00000000025BC1B0:4096
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL_read: -1
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL_get_error: 2
2014/02/18 15:46:12 [debug] 12839#0: *2 delete posted event
00007F29CC9D11B0
2014/02/18 15:46:12 [debug] 12839#0: *2 http upstream request:
"/index.cfm?"
2014/02/18 15:46:12 [debug] 12839#0: *2 http upstream process header
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL_read: -1
2014/02/18 15:46:12 [debug] 12839#0: *2 SSL_get_error: 2
2014/02/18 15:46:12 [debug] 12839#0: *2 post event 00007F29CC6901B0
2014/02/18 15:46:12 [debug] 12839#0: *2 delete posted event
00007F29CC6901B0
2014/02/18 15:46:12 [debug] 12839#0: *2 http upstream request:
"/index.cfm?"
2014/02/18 15:46:12 [debug] 12839#0: *2 http upstream send request handler
2014/02/18 15:46:12 [debug] 12839#0: *2 http upstream send request
2014/02/18 15:46:12 [debug] 12839#0: *2 chain writer in: 0000000000000000
2014/02/18 15:46:12 [debug] 12839#0: *2 event timer: 17, old: 1392735672713,
new: 1392735672713
2014/02/18 15:46:13 [debug] 12839#0: *2 post event 00007F29CC9D11B0
2014/02/18 15:46:13 [debug] 12839#0: *2 post event 00007F29CC6901B0
2014/02/18 15:46:13 [debug] 12839#0: *2 delete posted event
00007F29CC6901B0
2014/02/18 15:46:13 [debug] 12839#0: *2 http upstream request:
"/index.cfm?"
2014/02/18 15:46:13 [debug] 12839#0: *2 http upstream dummy handler
2014/02/18 15:46:13 [debug] 12839#0: *2 delete posted event
00007F29CC9D11B0
2014/02/18 15:46:13 [debug] 12839#0: *2 http upstream request:
"/index.cfm?"
2014/02/18 15:46:13 [debug] 12839#0: *2 http upstream process header
2014/02/18 15:46:13 [debug] 12839#0: *2 SSL_read: 110
2014/02/18 15:46:13 [debug] 12839#0: *2 SSL_read: 0
2014/02/18 15:46:13 [debug] 12839#0: *2 SSL_get_error: 6
2014/02/18 15:46:13 [debug] 12839#0: *2 peer shutdown SSL cleanly
2014/02/18 15:46:13 [debug] 12839#0: *2 http proxy status 200 "200 OK"
2014/02/18 15:46:13 [debug] 12839#0: *2 http proxy header: "Content-Type:
text/html; charset=UTF-8"
2014/02/18 15:46:13 [debug] 12839#0: *2 http proxy header: "Content-Length:
0"
2014/02/18 15:46:13 [debug] 12839#0: *2 http proxy header: "Server:
Jetty(9.0.6.v20130930)"
2014/02/18 15:46:13 [debug] 12839#0: *2 http proxy header done
2014/02/18 15:46:13 [debug] 12839#0: *2 xslt filter header
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy header filter
2014/02/18 15:46:13 [debug] 12839#0: *2 malloc: 00000000025CC7E0:228
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy deflate out:
ni:00000000025CC8B1 no:00000000025B7685 ai:0 ao:26 rc:0
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy:1 create SYN_REPLY frame
00000000025A6A88: len:229
2014/02/18 15:46:13 [debug] 12839#0: *2 http cleanup add: 00000000025A6AC8
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy frame out: 00000000025A6A88
sid:1 prio:2 bl:1 len:229
2014/02/18 15:46:13 [debug] 12839#0: *2 malloc: 00000000025CE6C0:16384
2014/02/18 15:46:13 [debug] 12839#0: *2 SSL buf copy: 237
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy:1 SYN_REPLY frame
00000000025A6A88 was sent
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy frame sent: 00000000025A6A88
sid:1 bl:1 len:229
2014/02/18 15:46:13 [debug] 12839#0: *2 http cacheable: 0
2014/02/18 15:46:13 [debug] 12839#0: *2 http proxy filter init s:200 h:0 c:0
l:0
2014/02/18 15:46:13 [debug] 12839#0: *2 http upstream process upstream
2014/02/18 15:46:13 [debug] 12839#0: *2 pipe read upstream: 1
2014/02/18 15:46:13 [debug] 12839#0: *2 pipe preread: 0
2014/02/18 15:46:13 [debug] 12839#0: *2 pipe recv chain: 0
2014/02/18 15:46:13 [debug] 12839#0: *2 pipe buf free s:0 t:1 f:0
00000000025BC1B0, pos 00000000025BC21E, size: 0 file: 0, size: 0
2014/02/18 15:46:13 [debug] 12839#0: *2 pipe length: 0
2014/02/18 15:46:13 [debug] 12839#0: *2 pipe write downstream: 1
2014/02/18 15:46:13 [debug] 12839#0: *2 pipe write downstream done
2014/02/18 15:46:13 [debug] 12839#0: *2 event timer del: 17: 1392735672713
2014/02/18 15:46:13 [debug] 12839#0: *2 event timer add: 17:
900000:1392735673435
2014/02/18 15:46:13 [debug] 12839#0: *2 http upstream exit:
0000000000000000
2014/02/18 15:46:13 [debug] 12839#0: *2 finalize http upstream request: 0
2014/02/18 15:46:13 [debug] 12839#0: *2 finalize http proxy request
2014/02/18 15:46:13 [debug] 12839#0: *2 free rr peer 1 0
2014/02/18 15:46:13 [debug] 12839#0: *2 SSL_shutdown: 1
2014/02/18 15:46:13 [debug] 12839#0: *2 close http upstream connection: 17
2014/02/18 15:46:13 [debug] 12839#0: *2 free: 00000000025B81A0
2014/02/18 15:46:13 [debug] 12839#0: *2 free: 00000000025CBB30
2014/02/18 15:46:13 [debug] 12839#0: *2 free: 00000000025328D0
2014/02/18 15:46:13 [debug] 12839#0: *2 free: 000000000252BB20, unused: 0
2014/02/18 15:46:13 [debug] 12839#0: *2 event timer del: 17: 1392735673435
2014/02/18 15:46:13 [debug] 12839#0: *2 reusable connection: 0
2014/02/18 15:46:13 [debug] 12839#0: *2 http upstream temp fd: -1
2014/02/18 15:46:13 [debug] 12839#0: *2 http output filter "/index.cfm?"
2014/02/18 15:46:13 [debug] 12839#0: *2 http copy filter: "/index.cfm?"
2014/02/18 15:46:13 [debug] 12839#0: *2 image filter
2014/02/18 15:46:13 [debug] 12839#0: *2 xslt filter body
2014/02/18 15:46:13 [debug] 12839#0: *2 http postpone filter "/index.cfm?"
00007FFF05E55010
2014/02/18 15:46:13 [debug] 12839#0: *2 write new buf t:0 f:0
0000000000000000, pos 0000000000000000, size: 0 file: 0, size: 0
2014/02/18 15:46:13 [debug] 12839#0: *2 http write filter: l:1 f:0 s:0
2014/02/18 15:46:13 [debug] 12839#0: *2 http write filter limit 0
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy:1 create DATA frame
00000000025A6A88: len:0 flags:1
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy frame out: 00000000025A6A88
sid:1 prio:2 bl:0 len:0
2014/02/18 15:46:13 [debug] 12839#0: *2 SSL buf copy: 8
2014/02/18 15:46:13 [debug] 12839#0: *2 SSL to write: 245
2014/02/18 15:46:13 [debug] 12839#0: *2 SSL_write: 245
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy:1 DATA frame 00000000025A6A88
was sent
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy frame sent: 00000000025A6A88
sid:1 bl:0 len:0
2014/02/18 15:46:13 [debug] 12839#0: *2 http write filter 0000000000000000
2014/02/18 15:46:13 [debug] 12839#0: *2 http copy filter: 0 "/index.cfm?"
2014/02/18 15:46:13 [debug] 12839#0: *2 http finalize request: 0,
"/index.cfm?" a:1, c:1
2014/02/18 15:46:13 [debug] 12839#0: *2 http request count:1 blk:0
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy close stream 1, queued 0,
processing 1
2014/02/18 15:46:13 [debug] 12839#0: *2 http close request
2014/02/18 15:46:13 [debug] 12839#0: *2 http log handler
2014/02/18 15:46:13 [debug] 12839#0: *2 run cleanup: 00000000025A61D0
2014/02/18 15:46:13 [debug] 12839#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:46:13 [debug] 12839#0: *2 free: 00000000025BC1B0
2014/02/18 15:46:13 [debug] 12839#0: *2 free: 00000000025A4B00, unused: 4
2014/02/18 15:46:13 [debug] 12839#0: *2 free: 00000000025A5B10, unused: 8
2014/02/18 15:46:13 [debug] 12839#0: *2 free: 00000000025B7190, unused:
2272
2014/02/18 15:46:13 [debug] 12839#0: *2 post event 00007F29CC9D1148
2014/02/18 15:46:13 [debug] 12839#0: *2 delete posted event
00007F29CC9D1148
2014/02/18 15:46:13 [debug] 12839#0: *2 free: 00000000025A3AF0, unused:
3272
2014/02/18 15:46:13 [debug] 12839#0: *2 free: 00000000025CE6C0
2014/02/18 15:46:13 [debug] 12839#0: *2 reusable connection: 1
2014/02/18 15:46:13 [debug] 12839#0: *2 event timer add: 15:
180000:1392734953435
2014/02/18 15:46:13 [debug] 12839#0: *2 post event 00007F29CC9D1148
2014/02/18 15:46:13 [debug] 12839#0: *2 delete posted event
00007F29CC9D1148
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy keepalive handler
2014/02/18 15:46:13 [debug] 12839#0: *2 reusable connection: 0
2014/02/18 15:46:13 [debug] 12839#0: *2 posix_memalign:
00000000025C98B0:4096 @16
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy read handler
2014/02/18 15:46:13 [debug] 12839#0: *2 SSL_read: 543
2014/02/18 15:46:13 [debug] 12839#0: *2 SSL_read: -1
2014/02/18 15:46:13 [debug] 12839#0: *2 SSL_get_error: 2
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy process frame head:80030001 f:1
l:519
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy SYN_STREAM frame sid:3 prio:3
2014/02/18 15:46:13 [debug] 12839#0: *2 posix_memalign:
00000000025CA8C0:4096 @16
2014/02/18 15:46:13 [debug] 12839#0: *2 posix_memalign:
00000000025A3AF0:4096 @16
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy process HEADERS 509 of 509
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy inflate out:
ni:00007F29CC64F21F no:00000000025A3D03 ai:0 ao:524 rc:0
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy HEADERS block consists of 10
entries
2014/02/18 15:46:13 [debug] 12839#0: *2 http uri: "/favicon.ico"
2014/02/18 15:46:13 [debug] 12839#0: *2 http args: ""
2014/02/18 15:46:13 [debug] 12839#0: *2 http exten: "ico"
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy http request line: "GET
/favicon.ico HTTP/1.1"
2014/02/18 15:46:13 [debug] 12839#0: *2 http header: "host:
www.example.org"
2014/02/18 15:46:13 [debug] 12839#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:46:13 [debug] 12839#0: *2 http header: "accept:
text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8"
2014/02/18 15:46:13 [debug] 12839#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:46:13 [debug] 12839#0: *2 http header: "cookie:
cfid=b0fc4a14-0812-48b6-aea7-077c7b61cca7; cftoken=0;
_ga=GA1.2.982493482.1392732645; JSESSIONID=5ln6ihdqossy18j3j9ouz680c"
2014/02/18 15:46:13 [debug] 12839#0: *2 http header: "dnt: 1"
2014/02/18 15:46:13 [debug] 12839#0: *2 generic phase: 0
2014/02/18 15:46:13 [debug] 12839#0: *2 rewrite phase: 1
2014/02/18 15:46:13 [debug] 12839#0: *2 http script regex: "^/\+"
2014/02/18 15:46:13 [notice] 12839#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:46:13 [debug] 12839#0: *2 http script var
2014/02/18 15:46:13 [debug] 12839#0: *2 http script var: "GET"
2014/02/18 15:46:13 [debug] 12839#0: *2 http script regex:
"^(GET|HEAD|POST)$"
2014/02/18 15:46:13 [notice] 12839#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:46:13 [debug] 12839#0: *2 http script if
2014/02/18 15:46:13 [debug] 12839#0: *2 http script if: false
2014/02/18 15:46:13 [debug] 12839#0: *2 test location: "/"
2014/02/18 15:46:13 [debug] 12839#0: *2 test location: "core/"
2014/02/18 15:46:13 [debug] 12839#0: *2 test location: "includes/"
2014/02/18 15:46:13 [debug] 12839#0: *2 test location: "favicon.ico"
2014/02/18 15:46:13 [debug] 12839#0: *2 using configuration "=/favicon.ico"
2014/02/18 15:46:13 [debug] 12839#0: *2 http cl:-1 max:1048576
2014/02/18 15:46:13 [debug] 12839#0: *2 rewrite phase: 3
2014/02/18 15:46:13 [debug] 12839#0: *2 post rewrite phase: 4
2014/02/18 15:46:13 [debug] 12839#0: *2 generic phase: 5
2014/02/18 15:46:13 [debug] 12839#0: *2 generic phase: 6
2014/02/18 15:46:13 [debug] 12839#0: *2 generic phase: 7
2014/02/18 15:46:13 [debug] 12839#0: *2 generic phase: 8
2014/02/18 15:46:13 [debug] 12839#0: *2 access phase: 9
2014/02/18 15:46:13 [debug] 12839#0: *2 access phase: 10
2014/02/18 15:46:13 [debug] 12839#0: *2 post access phase: 11
2014/02/18 15:46:13 [debug] 12839#0: *2 try files phase: 12
2014/02/18 15:46:13 [debug] 12839#0: *2 content phase: 13
2014/02/18 15:46:13 [debug] 12839#0: *2 content phase: 14
2014/02/18 15:46:13 [debug] 12839#0: *2 content phase: 15
2014/02/18 15:46:13 [debug] 12839#0: *2 content phase: 16
2014/02/18 15:46:13 [debug] 12839#0: *2 content phase: 17
2014/02/18 15:46:13 [debug] 12839#0: *2 content phase: 18
2014/02/18 15:46:13 [debug] 12839#0: *2 http filename:
"/usr/share/nginx/html/example.org/favicon.ico"
2014/02/18 15:46:13 [debug] 12839#0: *2 add cleanup: 00000000025CB828
2014/02/18 15:46:13 [debug] 12839#0: *2 malloc: 00000000024A8F00:144
2014/02/18 15:46:13 [debug] 12839#0: *2 malloc: 00000000024B2120:53
2014/02/18 15:46:13 [debug] 12839#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:46:13 [debug] 12839#0: *2 http static fd: 16
2014/02/18 15:46:13 [debug] 12839#0: *2 xslt filter header
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy header filter
2014/02/18 15:46:13 [debug] 12839#0: *2 malloc: 000000000252AE40:315
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy deflate out:
ni:000000000252AF6B no:00000000025A4431 ai:0 ao:44 rc:0
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy:3 create SYN_REPLY frame
00000000025A4460: len:313
2014/02/18 15:46:13 [debug] 12839#0: *2 http cleanup add: 00000000025CB8A8
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy frame out: 00000000025A4460
sid:3 prio:3 bl:1 len:313
2014/02/18 15:46:13 [debug] 12839#0: *2 malloc: 00000000025B7190:16384
2014/02/18 15:46:13 [debug] 12839#0: *2 SSL buf copy: 321
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy:3 SYN_REPLY frame
00000000025A4460 was sent
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy frame sent: 00000000025A4460
sid:3 bl:1 len:313
2014/02/18 15:46:13 [debug] 12839#0: *2 http output filter "/favicon.ico?"
2014/02/18 15:46:13 [debug] 12839#0: *2 http copy filter: "/favicon.ico?"
2014/02/18 15:46:13 [debug] 12839#0: *2 posix_memalign:
00000000025A4B00:4096 @16
2014/02/18 15:46:13 [debug] 12839#0: *2 read: 16, 00000000025A4B20, 3262, 0
2014/02/18 15:46:13 [debug] 12839#0: *2 image filter
2014/02/18 15:46:13 [debug] 12839#0: *2 xslt filter body
2014/02/18 15:46:13 [debug] 12839#0: *2 http postpone filter "/favicon.ico?"
00000000025A4560
2014/02/18 15:46:13 [debug] 12839#0: *2 write new buf t:1 f:1
00000000025A4B20, pos 00000000025A4B20, size: 3262 file: 0, size: 3262
2014/02/18 15:46:13 [debug] 12839#0: *2 http write filter: l:1 f:0 s:3262
2014/02/18 15:46:13 [debug] 12839#0: *2 http write filter limit 0
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy:3 create DATA frame
00000000025A4460: len:3262 flags:1
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy frame out: 00000000025A4460
sid:3 prio:3 bl:0 len:3262
2014/02/18 15:46:13 [debug] 12839#0: *2 SSL buf copy: 8
2014/02/18 15:46:13 [debug] 12839#0: *2 SSL buf copy: 3262
2014/02/18 15:46:13 [debug] 12839#0: *2 SSL to write: 3591
2014/02/18 15:46:13 [debug] 12839#0: *2 SSL_write: 3591
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy:3 DATA frame 00000000025A4460
was sent
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy frame sent: 00000000025A4460
sid:3 bl:0 len:3262
2014/02/18 15:46:13 [debug] 12839#0: *2 http write filter 0000000000000000
2014/02/18 15:46:13 [debug] 12839#0: *2 http copy filter: 0 "/favicon.ico?"
2014/02/18 15:46:13 [debug] 12839#0: *2 http finalize request: 0,
"/favicon.ico?" a:1, c:1
2014/02/18 15:46:13 [debug] 12839#0: *2 http request count:1 blk:0
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy close stream 3, queued 0,
processing 1
2014/02/18 15:46:13 [debug] 12839#0: *2 http close request
2014/02/18 15:46:13 [debug] 12839#0: *2 http log handler
2014/02/18 15:46:13 [debug] 12839#0: *2 run cleanup: 00000000025CB828
2014/02/18 15:46:13 [debug] 12839#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:46:13 [debug] 12839#0: *2 free: 00000000025CA8C0, unused: 0
2014/02/18 15:46:13 [debug] 12839#0: *2 free: 00000000025A3AF0, unused:
1272
2014/02/18 15:46:13 [debug] 12839#0: *2 free: 00000000025A4B00, unused: 802
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy process frame head:80030009 f:0
l:8
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy WINDOW_UPDATE sid:3
delta:268369920
2014/02/18 15:46:13 [info] 12839#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:46:13 [debug] 12839#0: *2 spdy write RST_STREAM sid:3 st:2
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy frame out: 00000000025C9BE8
sid:0 prio:7 bl:0 len:8
2014/02/18 15:46:13 [debug] 12839#0: *2 SSL buf copy: 16
2014/02/18 15:46:13 [debug] 12839#0: *2 SSL to write: 16
2014/02/18 15:46:13 [debug] 12839#0: *2 SSL_write: 16
2014/02/18 15:46:13 [debug] 12839#0: *2 spdy frame sent: 00000000025C9BE8
sid:0 bl:0 len:8
2014/02/18 15:46:13 [debug] 12839#0: *2 free: 00000000025C98B0, unused:
3096
2014/02/18 15:46:13 [debug] 12839#0: *2 free: 00000000025B7190
2014/02/18 15:46:13 [debug] 12839#0: *2 reusable connection: 1
2014/02/18 15:46:13 [debug] 12839#0: *2 event timer: 15, old: 1392734953435,
new: 1392734953471

Posted at Nginx Forum: http://forum.nginx.org/read.php?2,247692,247695#msg-247695