upstream prematurely closed connection while reading response header from upstream

Jiri Horky jiri.horky at gmail.com
Thu Oct 16 22:26:39 UTC 2014


Hi Maxim,

here is the debug log of one failed connection:

2014/10/17 00:18:30 [debug] 25783#0: *8190 http keepalive handler
2014/10/17 00:18:30 [debug] 25783#0: *8190 malloc: 0000000000BE44F0:1024
2014/10/17 00:18:30 [debug] 25783#0: *8190 SSL_read: 1024
2014/10/17 00:18:30 [debug] 25783#0: *8190 reusable connection: 0
2014/10/17 00:18:30 [debug] 25783#0: *8190 posix_memalign:
0000000000D41510:4096 @16
2014/10/17 00:18:30 [debug] 25783#0: *8190 event timer del: 104:
1413497973959
2014/10/17 00:18:30 [debug] 25783#0: *8190 http process request line
2014/10/17 00:18:30 [debug] 25783#0: *8190 http request line: "GET
/es-mx/ HTTP/1.1"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http uri: "/es-mx/"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http args: ""
2014/10/17 00:18:30 [debug] 25783#0: *8190 http exten: ""
2014/10/17 00:18:30 [debug] 25783#0: *8190 http process request header line
2014/10/17 00:18:30 [debug] 25783#0: *8190 http header: "Host:
my.upstream.com"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http header: "Connection:
keep-alive"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http header: "Accept:
text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http header: "User-Agent:
Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like
Gecko) Chrome/37.0.2062.124 Safari/537.36"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http header: "Referer:
https://id.upstream.com/es-mx/confirm/registration?token=TOKEN"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http header:
"Accept-Encoding: gzip,deflate"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http header:
"Accept-Language: es-ES,es;q=0.8"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http alloc large header buffer
2014/10/17 00:18:30 [debug] 25783#0: *8190 posix_memalign:
0000000000C66DE0:256 @16
2014/10/17 00:18:30 [debug] 25783#0: *8190 malloc: 0000000000E8A030:8192
2014/10/17 00:18:30 [debug] 25783#0: *8190 http large header alloc:
0000000000E8A030 8192
2014/10/17 00:18:30 [debug] 25783#0: *8190 http large header copy: 572
2014/10/17 00:18:30 [debug] 25783#0: *8190 SSL_read: 326
2014/10/17 00:18:30 [debug] 25783#0: *8190 SSL_read: -1
2014/10/17 00:18:30 [debug] 25783#0: *8190 SSL_get_error: 2
2014/10/17 00:18:30 [debug] 25783#0: *8190 http header: "Cookie:
locale2=es-mx; osc_ot=wr%3E%3Eun%3Eun; x-otid=wr%3E%3Eun%3Eun;
ld893_pop_g=1413877218; ld893_pop_s=1413877218;
ID-params-prod="registered=true&refreshIdSession=true&LOGIN_SUCCESS=true";
IDT2=IDTN-33612-GIxblg2ptOvu5R5nlevAy39OTcsyK3i1U6f35444; s_cc=true;
s_nr2=1413877237532-New; osc_v12=Website;
osc_v13=Website%20%7C%20Referral;
osc_v14=Website%20%7C%20Referral%20%7C%20;
osc_v15=Website%20%7C%20Referral%20%7C%20;
osc_v27=Website%20%7C%20Referral; osc_v42=web; s_sq=%5B%5BB%5D%5D;
s_vi=[CS]v1|2A2021EC0531011A-6000010F20029A71[CE];
__utma=1.338233621.1413877155.1413877155.1413877155.1;
__utmb=1.2.10.1413877155; __utmc=1;
__utmz=1.1413877155.1.1.utmcsr=dub126.mail.live.com|utmccn=(referral)|utmcmd=referral|utmcct=/;
s_fid=5230BF2FDF8FC79B-2A08DC4D856F30C9; osc_omcid=undefined;
mySessionId=pYb401tEc5En9InZ;
myLocalIdSession="IDTN-33612-GIxblg2ptOvu5R5nlevAy39OTcsyK3i1U6f35444:2""
2014/10/17 00:18:30 [debug] 25783#0: *8190 http header done
2014/10/17 00:18:30 [debug] 25783#0: *8190 generic phase: 0
2014/10/17 00:18:30 [debug] 25783#0: *8190 rewrite phase: 1
2014/10/17 00:18:30 [debug] 25783#0: *8190 test location: "/"
2014/10/17 00:18:30 [debug] 25783#0: *8190 using configuration "/"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http cl:-1 max:10485760
2014/10/17 00:18:30 [debug] 25783#0: *8190 rewrite phase: 3
2014/10/17 00:18:30 [debug] 25783#0: *8190 post rewrite phase: 4
2014/10/17 00:18:30 [debug] 25783#0: *8190 generic phase: 5
2014/10/17 00:18:30 [debug] 25783#0: *8190 generic phase: 6
2014/10/17 00:18:30 [debug] 25783#0: *8190 generic phase: 7
2014/10/17 00:18:30 [debug] 25783#0: *8190 access phase: 8
2014/10/17 00:18:30 [debug] 25783#0: *8190 access phase: 9
2014/10/17 00:18:30 [debug] 25783#0: *8190 access phase: 10
2014/10/17 00:18:30 [debug] 25783#0: *8190 post access phase: 11
2014/10/17 00:18:30 [debug] 25783#0: *8190 posix_memalign:
0000000000E03DA0:4096 @16
2014/10/17 00:18:30 [debug] 25783#0: *8190 http init upstream, client
timer: 0
2014/10/17 00:18:30 [debug] 25783#0: *8190 http script copy: "Host: "
2014/10/17 00:18:30 [debug] 25783#0: *8190 http script var:
"my.upstream.com"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http script copy: "
2014/10/17 00:18:30 [debug] 25783#0: *8190 http script copy: "X-Real-IP: "
2014/10/17 00:18:30 [debug] 25783#0: *8190 http script var: "201.138.52.240"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http script copy: "
2014/10/17 00:18:30 [debug] 25783#0: *8190 http script copy:
"X-Forwarded-For: "
2014/10/17 00:18:30 [debug] 25783#0: *8190 http script var: "201.138.52.240"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http script copy: "
2014/10/17 00:18:30 [debug] 25783#0: *8190 http script copy:
"Connection: close
2014/10/17 00:18:30 [debug] 25783#0: *8190 http script copy: ""
2014/10/17 00:18:30 [debug] 25783#0: *8190 http script copy: ""
2014/10/17 00:18:30 [debug] 25783#0: *8190 http proxy header: "Accept:
text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http proxy header:
"User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36
(KHTML, like Gecko) Chrome/37.0.2062.124 Safari/537.36"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http proxy header: "Referer:
https://id.upstream.com/es-mx/confirm/registration?token=TOKEN"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http proxy header:
"Accept-Encoding: gzip,deflate"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http proxy header:
"Accept-Language: es-ES,es;q=0.8"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http proxy header: "Cookie:
locale2=es-mx; osc_ot=wr%3E%3Eun%3Eun; x-otid=wr%3E%3Eun%3Eun;
ld893_pop_g=1413877218; ld893_pop_s=1413877218;
ID-params-prod="registered=true&refreshIdSession=true&LOGIN_SUCCESS=true";
IDT2=IDTN-33612-GIxblg2ptOvu5R5nlevAy39OTcsyK3i1U6f35444; s_cc=true;
s_nr2=1413877237532-New; osc_v12=Website;
osc_v13=Website%20%7C%20Referral;
osc_v14=Website%20%7C%20Referral%20%7C%20;
osc_v15=Website%20%7C%20Referral%20%7C%20;
osc_v27=Website%20%7C%20Referral; osc_v42=web; s_sq=%5B%5BB%5D%5D;
s_vi=[CS]v1|2A2021EC0531011A-6000010F20029A71[CE];
__utma=1.338233621.1413877155.1413877155.1413877155.1;
__utmb=1.2.10.1413877155; __utmc=1;
__utmz=1.1413877155.1.1.utmcsr=dub126.mail.live.com|utmccn=(referral)|utmcmd=referral|utmcct=/;
s_fid=5230BF2FDF8FC79B-2A08DC4D856F30C9; osc_omcid=undefined;
mySessionId=pYb401tEc5En9InZ;
myLocalIdSession="IDTN-33612-GIxblg2ptOvu5R5nlevAy39OTcsyK3i1U6f35444:2""
2014/10/17 00:18:30 [debug] 25783#0: *8190 http proxy header:
2014/10/17 00:18:30 [debug] 25783#0: *8190 http cleanup add:
0000000000D424F8
2014/10/17 00:18:30 [debug] 25783#0: *8190 init keepalive peer
2014/10/17 00:18:30 [debug] 25783#0: *8190 get keepalive peer
2014/10/17 00:18:30 [debug] 25783#0: *8190 get ip hash peer, try: 1
2014/10/17 00:18:30 [debug] 25783#0: *8190 get rr peer, try: 1
2014/10/17 00:18:30 [debug] 25783#0: *8190 get keepalive peer: using
connection 0000000000A7D4F0
2014/10/17 00:18:30 [debug] 25783#0: *8190 http upstream connect: -4
2014/10/17 00:18:30 [debug] 25783#0: *8190 http upstream send request
2014/10/17 00:18:30 [debug] 25783#0: *8190 chain writer buf fl:1 s:1405
2014/10/17 00:18:30 [debug] 25783#0: *8190 chain writer in: 0000000000E04A58
2014/10/17 00:18:30 [debug] 25783#0: *8190 SSL buf copy: 1405
2014/10/17 00:18:30 [debug] 25783#0: *8190 SSL to write: 1405
2014/10/17 00:18:30 [debug] 25783#0: *8190 SSL_write: 1405
2014/10/17 00:18:30 [debug] 25783#0: *8190 chain writer out:
0000000000000000
2014/10/17 00:18:30 [debug] 25783#0: *8190 event timer add: 219:
90000:1413498000113
2014/10/17 00:18:30 [debug] 25783#0: *8190 http finalize request: -4,
"/es-mx/?" a:1, c:2
2014/10/17 00:18:30 [debug] 25783#0: *8190 http request count:2 blk:0
2014/10/17 00:18:30 [debug] 25783#0: *8190 http run request: "/es-mx/?"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http upstream check client,
write event:1, "/es-mx/"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http upstream recv(): -1 (11:
Resource temporarily unavailable)
2014/10/17 00:18:30 [debug] 25783#0: *8190 http upstream request: "/es-mx/?"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http upstream process header
2014/10/17 00:18:30 [debug] 25783#0: *8190 malloc: 0000000000C44D60:8192
2014/10/17 00:18:30 [debug] 25783#0: *8190 SSL_read: 0
2014/10/17 00:18:30 [debug] 25783#0: *8190 SSL_get_error: 6
2014/10/17 00:18:30 [debug] 25783#0: *8190 peer shutdown SSL cleanly
2014/10/17 00:18:30 [error] 25783#0: *8190 upstream prematurely closed
connection while reading response header from upstream, client:
201.138.52.240, server: my.upstream.com, request: "GET /es-mx/
HTTP/1.1", upstream: "https://1.1.1.1:8888/es-mx/", host:
"my.upstream.com", referrer:
"https://id.upstream.com/es-mx/confirm/registration?token=TOKEN"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http next upstream, 2
2014/10/17 00:18:30 [debug] 25783#0: *8190 free keepalive peer
2014/10/17 00:18:30 [debug] 25783#0: *8190 free rr peer 1 4
2014/10/17 00:18:30 [debug] 25783#0: *8190 close http upstream
connection: 219
2014/10/17 00:18:30 [debug] 25783#0: *8190 SSL_shutdown: 1
2014/10/17 00:18:30 [debug] 25783#0: *8190 free: 0000000000E8D020
2014/10/17 00:18:30 [debug] 25783#0: *8190 free: 0000000000CF6D30
2014/10/17 00:18:30 [debug] 25783#0: *8190 free: 0000000000A93A90
2014/10/17 00:18:30 [debug] 25783#0: *8190 free: 0000000000A93A00, unused: 0
2014/10/17 00:18:30 [debug] 25783#0: *8190 event timer del: 219:
1413498000113
2014/10/17 00:18:30 [debug] 25783#0: *8190 reusable connection: 0
2014/10/17 00:18:30 [debug] 25783#0: *8190 get keepalive peer
2014/10/17 00:18:30 [debug] 25783#0: *8190 get ip hash peer, try: 1
2014/10/17 00:18:30 [debug] 25783#0: *8190 get rr peer, try: 1
2014/10/17 00:18:30 [debug] 25783#0: *8190 get keepalive peer: using
connection 0000000000A799E0
2014/10/17 00:18:30 [debug] 25783#0: *8190 http upstream connect: -4
2014/10/17 00:18:30 [debug] 25783#0: *8190 posix_memalign:
0000000000E6D280:4096 @16
2014/10/17 00:18:30 [debug] 25783#0: *8190 http upstream send request
2014/10/17 00:18:30 [debug] 25783#0: *8190 chain writer buf fl:1 s:1405
2014/10/17 00:18:30 [debug] 25783#0: *8190 chain writer in: 0000000000E04C68
2014/10/17 00:18:30 [debug] 25783#0: *8190 SSL buf copy: 1405
2014/10/17 00:18:30 [debug] 25783#0: *8190 SSL to write: 1405
2014/10/17 00:18:30 [debug] 25783#0: *8190 SSL_write: 1405
2014/10/17 00:18:30 [debug] 25783#0: *8190 chain writer out:
0000000000000000
2014/10/17 00:18:30 [debug] 25783#0: *8190 event timer add: 65:
90000:1413498000114
2014/10/17 00:18:30 [debug] 25783#0: *8190 http upstream request: "/es-mx/?"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http upstream process header
2014/10/17 00:18:30 [debug] 25783#0: *8190 SSL_read: 8192
2014/10/17 00:18:30 [debug] 25783#0: *8190 http proxy status 200 "200 OK"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http proxy header:
"Content-Length: 9960"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http proxy header:
"Content-Type: text/html"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http proxy header:
"Set-Cookie: mySessionId=pYb401tEc5En9InZ; Expires=Thu, 16 Oct 2014
22:33:30 GMT; Path=/; Domain=.my.upstream.com; Secure; HTTPOnly"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http proxy header:
"Set-Cookie: MY-params=; Expires=Thu, 16 Oct 2014 22:18:30 GMT; Path=/;
Domain=.ff.upstream.com; Secure; HTTPOnly"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http proxy header:
"Set-Cookie: locale2=es-mx; Expires=Wed, 04 Nov 2082 01:32:37 GMT;
Path=/; Domain=.upstream.com; Secure; HTTPOnly"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http proxy header:
"Set-Cookie: ID-params-prod=; Expires=Thu, 16 Oct 2014 22:18:30 GMT;
Path=/; Domain=.upstream.com; Secure; HTTPOnly"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http proxy header:
"Set-Cookie: fbSecThr=true; Path=/; Domain=.my.upstream.com; Secure;
HTTPOnly"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http proxy header:
"Set-Cookie:
myLocalIdSession="IDTN-33612-GIxblg2ptOvu5R5nlevAy39OTcsyK3i1U6f35444:2"; Expires=Thu,
16 Oct 2014 22:33:30 GMT; Path=/; Domain=.my.upstream.com; Secure; HTTPOnly"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http proxy header:
"Last-Modified: Wed, 15 Oct 2014 16:26:53 GMT"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http proxy header:
"Cache-Control: max-age=0, private"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http proxy header:
"Strict-Transport-Security: max-age=31536000"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http proxy header: "Date:
Thu, 16 Oct 2014 22:18:30 GMT"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http proxy header done
2014/10/17 00:18:30 [debug] 25783#0: *8190 HTTP/1.1 200 OK
2014/10/17 00:18:30 [debug] 25783#0: *8190 write new buf t:1 f:0
0000000000E6DAC8, pos 0000000000E6DAC8, size: 1016 file: 0, size: 0
2014/10/17 00:18:30 [debug] 25783#0: *8190 http write filter: l:0 f:0 s:1016
2014/10/17 00:18:30 [debug] 25783#0: *8190 http cacheable: 0
2014/10/17 00:18:30 [debug] 25783#0: *8190 http proxy filter init s:200
h:0 c:0 l:9960
2014/10/17 00:18:30 [debug] 25783#0: *8190 http upstream process upstream
2014/10/17 00:18:30 [debug] 25783#0: *8190 pipe read upstream: 1
2014/10/17 00:18:30 [debug] 25783#0: *8190 pipe preread: 7251
2014/10/17 00:18:30 [debug] 25783#0: *8190 input buf #0
2014/10/17 00:18:30 [debug] 25783#0: *8190 malloc: 0000000000D1EBE0:4096
2014/10/17 00:18:30 [debug] 25783#0: *8190 SSL_read: 2709
2014/10/17 00:18:30 [debug] 25783#0: *8190 SSL_read: -1
2014/10/17 00:18:30 [debug] 25783#0: *8190 SSL_get_error: 2
2014/10/17 00:18:30 [debug] 25783#0: *8190 SSL_read: -1
2014/10/17 00:18:30 [debug] 25783#0: *8190 SSL_get_error: 2
2014/10/17 00:18:30 [debug] 25783#0: *8190 pipe recv chain: 2709
2014/10/17 00:18:30 [debug] 25783#0: *8190 pipe buf in   s:1 t:1 f:0
0000000000C44D60, pos 0000000000C4510D, size: 7251 file: 0, size: 0
2014/10/17 00:18:30 [debug] 25783#0: *8190 pipe buf free s:0 t:1 f:0
0000000000D1EBE0, pos 0000000000D1EBE0, size: 2709 file: 0, size: 0
2014/10/17 00:18:30 [debug] 25783#0: *8190 pipe length: 2709
2014/10/17 00:18:30 [debug] 25783#0: *8190 input buf #1
2014/10/17 00:18:30 [debug] 25783#0: *8190 pipe write downstream: 1
2014/10/17 00:18:30 [debug] 25783#0: *8190 pipe write downstream flush in
2014/10/17 00:18:30 [debug] 25783#0: *8190 http output filter "/es-mx/?"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http copy filter: "/es-mx/?"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http postpone filter
"/es-mx/?" 0000000000E6DFD0
2014/10/17 00:18:30 [debug] 25783#0: *8190 http gzip filter
2014/10/17 00:18:30 [debug] 25783#0: *8190 malloc: 0000000000EB9680:139264
2014/10/17 00:18:30 [debug] 25783#0: *8190 gzip alloc: n:1 s:5928 a:8192
p:0000000000EB9680
2014/10/17 00:18:30 [debug] 25783#0: *8190 gzip alloc: n:16384 s:2
a:32768 p:0000000000EBB680
2014/10/17 00:18:30 [debug] 25783#0: *8190 gzip alloc: n:16384 s:2
a:32768 p:0000000000EC3680
2014/10/17 00:18:30 [debug] 25783#0: *8190 gzip alloc: n:16384 s:2
a:32768 p:0000000000ECB680
2014/10/17 00:18:30 [debug] 25783#0: *8190 gzip alloc: n:8192 s:4
a:32768 p:0000000000ED3680
2014/10/17 00:18:30 [debug] 25783#0: *8190 gzip in: 0000000000E6E190
2014/10/17 00:18:30 [debug] 25783#0: *8190 gzip in_buf:0000000000E6DFF0
ni:0000000000C4510D ai:7251
2014/10/17 00:18:30 [debug] 25783#0: *8190 malloc: 0000000000DF5FB0:4096
2014/10/17 00:18:30 [debug] 25783#0: *8190 deflate in:
ni:0000000000C4510D no:0000000000DF5FB0 ai:7251 ao:4096 fl:0 redo:0
2014/10/17 00:18:30 [debug] 25783#0: *8190 deflate out:
ni:0000000000C46D60 no:0000000000DF5FB0 ai:0 ao:4096 rc:0
2014/10/17 00:18:30 [debug] 25783#0: *8190 gzip in_buf:0000000000E6DFF0
pos:0000000000C4510D
2014/10/17 00:18:30 [debug] 25783#0: *8190 gzip in: 0000000000E6E1A0
2014/10/17 00:18:30 [debug] 25783#0: *8190 gzip in_buf:0000000000E6E0B0
ni:0000000000D1EBE0 ai:2709
2014/10/17 00:18:30 [debug] 25783#0: *8190 deflate in:
ni:0000000000D1EBE0 no:0000000000DF5FB0 ai:2709 ao:4096 fl:0 redo:0
2014/10/17 00:18:30 [debug] 25783#0: *8190 deflate out:
ni:0000000000D1F675 no:0000000000DF5FB0 ai:0 ao:4096 rc:0
2014/10/17 00:18:30 [debug] 25783#0: *8190 gzip in_buf:0000000000E6E0B0
pos:0000000000D1EBE0
2014/10/17 00:18:30 [debug] 25783#0: *8190 gzip in: 0000000000000000
2014/10/17 00:18:30 [debug] 25783#0: *8190 http copy filter: 0 "/es-mx/?"
2014/10/17 00:18:30 [debug] 25783#0: *8190 pipe write downstream done
2014/10/17 00:18:30 [debug] 25783#0: *8190 event timer: 65, old:
1413498000114, new: 1413498000129
2014/10/17 00:18:30 [debug] 25783#0: *8190 http upstream exit:
0000000000000000
2014/10/17 00:18:30 [debug] 25783#0: *8190 finalize http upstream request: 0
2014/10/17 00:18:30 [debug] 25783#0: *8190 finalize http proxy request
2014/10/17 00:18:30 [debug] 25783#0: *8190 free keepalive peer
2014/10/17 00:18:30 [debug] 25783#0: *8190 free keepalive peer: saving
connection 0000000000A799E0
2014/10/17 00:18:30 [debug] 25783#0: *8190 event timer del: 65:
1413498000114
2014/10/17 00:18:30 [debug] 25783#0: *8190 free rr peer 1 0
2014/10/17 00:18:30 [debug] 25783#0: *8190 http upstream temp fd: -1
2014/10/17 00:18:30 [debug] 25783#0: *8190 http output filter "/es-mx/?"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http copy filter: "/es-mx/?"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http postpone filter
"/es-mx/?" 00007FFFE5A241B0
2014/10/17 00:18:30 [debug] 25783#0: *8190 http gzip filter
2014/10/17 00:18:30 [debug] 25783#0: *8190 gzip in: 0000000000E6E170
2014/10/17 00:18:30 [debug] 25783#0: *8190 gzip in_buf:0000000000E6E210
ni:0000000000000000 ai:0
2014/10/17 00:18:30 [debug] 25783#0: *8190 deflate in:
ni:0000000000000000 no:0000000000DF5FB0 ai:0 ao:4096 fl:4 redo:0
2014/10/17 00:18:30 [debug] 25783#0: *8190 deflate out:
ni:0000000000000000 no:0000000000DF6C2F ai:0 ao:897 rc:1
2014/10/17 00:18:30 [debug] 25783#0: *8190 gzip in_buf:0000000000E6E210
pos:0000000000000000
2014/10/17 00:18:30 [debug] 25783#0: *8190 free: 0000000000EB9680
2014/10/17 00:18:30 [debug] 25783#0: *8190 posix_memalign:
0000000000E18990:4096 @16
2014/10/17 00:18:30 [debug] 25783#0: *8190 http chunk: 10
2014/10/17 00:18:30 [debug] 25783#0: *8190 http chunk: 3207
2014/10/17 00:18:30 [debug] 25783#0: *8190 write old buf t:1 f:0
0000000000E6DAC8, pos 0000000000E6DAC8, size: 1016 file: 0, size: 0
2014/10/17 00:18:30 [debug] 25783#0: *8190 write new buf t:1 f:0
0000000000E18A70, pos 0000000000E18A70, size: 5 file: 0, size: 0
2014/10/17 00:18:30 [debug] 25783#0: *8190 write new buf t:0 f:0
0000000000000000, pos 00000000006D7C08, size: 10 file: 0, size: 0
2014/10/17 00:18:30 [debug] 25783#0: *8190 write new buf t:1 f:0
0000000000DF5FB0, pos 0000000000DF5FB0, size: 3207 file: 0, size: 0
2014/10/17 00:18:30 [debug] 25783#0: *8190 write new buf t:0 f:0
0000000000000000, pos 00000000004B0C38, size: 7 file: 0, size: 0
2014/10/17 00:18:30 [debug] 25783#0: *8190 http write filter: l:1 f:1 s:4245
2014/10/17 00:18:30 [debug] 25783#0: *8190 http write filter limit 0
2014/10/17 00:18:30 [debug] 25783#0: *8190 malloc: 0000000000D2E0F0:16384
2014/10/17 00:18:30 [debug] 25783#0: *8190 SSL buf copy: 1016
2014/10/17 00:18:30 [debug] 25783#0: *8190 SSL buf copy: 5
2014/10/17 00:18:30 [debug] 25783#0: *8190 SSL buf copy: 10
2014/10/17 00:18:30 [debug] 25783#0: *8190 SSL buf copy: 3207
2014/10/17 00:18:30 [debug] 25783#0: *8190 SSL buf copy: 7
2014/10/17 00:18:30 [debug] 25783#0: *8190 SSL to write: 4245
2014/10/17 00:18:30 [debug] 25783#0: *8190 SSL_write: 4245
2014/10/17 00:18:30 [debug] 25783#0: *8190 http write filter
0000000000000000
2014/10/17 00:18:30 [debug] 25783#0: *8190 http copy filter: 0 "/es-mx/?"
2014/10/17 00:18:30 [debug] 25783#0: *8190 http finalize request: 0,
"/es-mx/?" a:1, c:1
2014/10/17 00:18:30 [debug] 25783#0: *8190 set http keepalive handler
2014/10/17 00:18:30 [debug] 25783#0: *8190 http close request
2014/10/17 00:18:30 [debug] 25783#0: *8190 http log handler
2014/10/17 00:18:30 [debug] 25783#0: *8190 free: 0000000000DF5FB0
2014/10/17 00:18:30 [debug] 25783#0: *8190 free: 0000000000000000
2014/10/17 00:18:30 [debug] 25783#0: *8190 free: 0000000000D1EBE0
2014/10/17 00:18:30 [debug] 25783#0: *8190 free: 0000000000C44D60
2014/10/17 00:18:30 [debug] 25783#0: *8190 free: 0000000000D41510, unused: 0
2014/10/17 00:18:30 [debug] 25783#0: *8190 free: 0000000000E03DA0, unused: 0
2014/10/17 00:18:30 [debug] 25783#0: *8190 free: 0000000000E6D280, unused: 0
2014/10/17 00:18:30 [debug] 25783#0: *8190 free: 0000000000E18990,
unused: 3356
2014/10/17 00:18:30 [debug] 25783#0: *8190 free: 0000000000BE44F0
2014/10/17 00:18:30 [debug] 25783#0: *8190 hc free: 0000000000000000 0
2014/10/17 00:18:30 [debug] 25783#0: *8190 hc busy: 0000000000E075C0 1
2014/10/17 00:18:30 [debug] 25783#0: *8190 free: 0000000000E8A030
2014/10/17 00:18:30 [debug] 25783#0: *8190 free: 0000000000D2E0F0
2014/10/17 00:18:30 [debug] 25783#0: *8190 reusable connection: 1
2014/10/17 00:18:30 [debug] 25783#0: *8190 event timer add: 104:
65000:1413497975129




More information about the nginx mailing list