Проблема nginx 1.2.4+mod zip+ssl

gatesat nginx-forum at nginx.us
Fri Oct 19 13:44:50 UTC 2012


Всем привет !

Столкнулся с проблемой, никак не могу понять в чем причина.
Суть проблемы - nginx не хочет отдавать через mod_zip по https-у то, что я
хочу забрать =) 
По http отдает. 

Схема стандартная - запрос к бэкенду, который возвращает нам 

Content-Type: application/zip
Content-Length: 126488906
Connection: keep-alive
Accept-Ranges: bytes
Content-Disposition: attachment; filename="Arch.zip";
X-Archive-Files: zip
Cache-Control: max-age=0

После чего конкретно на этом архиве я качаю до 46,9-47,1 МБ. после чего у
меня все отваливается с такими вот записями в логе

012/10/19 16:06:04 [debug] 32002#0: *102 http finalize request: 0,
"/files/Hollywood.jpg?" a:1, c:2
2012/10/19 16:06:04 [debug] 32002#0: *102 http wake parent request:
"/rest/download/stream/507d6aaae4b0be1d4bcd3f8a"
2012/10/19 16:06:04 [debug] 32002#0: *102 http posted request:
"/rest/download/stream/507d6aaae4b0be1d4bcd3f8a"
2012/10/19 16:06:04 [debug] 32002#0: *102 http writer handler:
"/rest/download/stream/507d6aaae4b0be1d4bcd3f8a?"
2012/10/19 16:06:04 [debug] 32002#0: *102 http output filter
"/rest/download/stream/507d6aaae4b0be1d4bcd3f8a"
2012/10/19 16:06:04 [debug] 32002#0: *102 http copy filter:
"/rest/download/stream/507d6aaae4b0be1d4bcd3f8a"
2012/10/19 16:06:04 [debug] 32002#0: *102 mod_zip: entering main request
body filter
2012/10/19 16:06:04 [debug] 32002#0: *102 mod_zip: restarting subrequests
2012/10/19 16:06:04 [debug] 32002#0: *102 mod_zip: sending pieces, starting
with piece 8 of total 21
2012/10/19 16:06:04 [debug] 32002#0: *102 mod_zip: no ranges / sending piece
type 0
2012/10/19 16:06:04 [debug] 32002#0: *102 image filter
2012/10/19 16:06:04 [debug] 32002#0: *102 xslt filter body
2012/10/19 16:06:04 [debug] 32002#0: *102 http postpone filter
"/rest/download/stream/507d6aaae4b0be1d4bcd3f8a" 0000000001F355A0
2012/10/19 16:06:04 [debug] 32002#0: *102 write new buf t:0 f:0
0000000000000000, pos 0000000001F35610, size: 107 file: 0, size: 0
2012/10/19 16:06:04 [debug] 32002#0: *102 http write filter: l:0 f:0 s:107
2012/10/19 16:06:04 [debug] 32002#0: *102 mod_zip: no ranges / sending piece
type 1
2012/10/19 16:06:04 [debug] 32002#0: *102 mod_zip: subrequest for
"/files/Info.txt?"
2012/10/19 16:06:04 [debug] 32002#0: *102 mod_zip: have a wait context for
"/files/Hollywood.jpg?"
2012/10/19 16:06:04 [debug] 32002#0: *102 mod_zip: wait
"/files/Hollywood.jpg?" done
2012/10/19 16:06:04 [debug] 32002#0: *102 posix_memalign:
0000000001F88910:4096 @16
2012/10/19 16:06:04 [debug] 32002#0: *102 http subrequest
"/files/Info.txt?"
2012/10/19 16:06:04 [debug] 32002#0: *102 mod_zip: subrequest for
"/files/Info.txt?" result 0, allocating some mem
 on main request's pool
2012/10/19 16:06:04 [debug] 32002#0: *102 mod_zip: subrequest for
"/files/Info.txt?" result 0
2012/10/19 16:06:04 [debug] 32002#0: *102 mod_zip: sent 2 pieces, last rc =
-2
2012/10/19 16:06:04 [debug] 32002#0: *102 http copy filter: -2
"/rest/download/stream/507d6aaae4b0be1d4bcd3f8a"
2012/10/19 16:06:04 [debug] 32002#0: *102 http writer output filter: -2,
"/rest/download/stream/507d6aaae4b0be1d4bcd3f8a"
2012/10/19 16:06:04 [debug] 32002#0: *102 event timer del: 14:
1350652024415
2012/10/19 16:06:04 [debug] 32002#0: *102 event timer add: 14:
60000:1350652024804
2012/10/19 16:06:04 [debug] 32002#0: *102 http posted request:
"/files/Info.txt?"
2012/10/19 16:06:04 [debug] 32002#0: *102 rewrite phase: 1
2012/10/19 16:06:04 [debug] 32002#0: *102 test location:
"/rest/download/stream/"
2012/10/19 16:06:04 [debug] 32002#0: *102 test location: "/files"
2012/10/19 16:06:04 [debug] 32002#0: *102 using configuration "/files"
2012/10/19 16:06:04 [debug] 32002#0: *102 http cl:-1 max:2097152000
2012/10/19 16:06:04 [debug] 32002#0: *102 rewrite phase: 3
2012/10/19 16:06:04 [debug] 32002#0: *102 rewrite phase: 4
2012/10/19 16:06:04 [debug] 32002#0: *102 post rewrite phase: 5
2012/10/19 16:06:04 [debug] 32002#0: *102 generic phase: 6
2012/10/19 16:06:04 [debug] 32002#0: *102 generic phase: 7
2012/10/19 16:06:04 [debug] 32002#0: *102 generic phase: 8
2012/10/19 16:06:04 [debug] 32002#0: *102 content phase: 14
2012/10/19 16:06:04 [debug] 32002#0: *102 content phase: 15
2012/10/19 16:06:04 [debug] 32002#0: *102 content phase: 16
2012/10/19 16:06:04 [debug] 32002#0: *102 content phase: 17
2012/10/19 16:06:04 [debug] 32002#0: *102 content phase: 18
2012/10/19 16:06:04 [debug] 32002#0: *102 content phase: 19
2012/10/19 16:06:04 [debug] 32002#0: *102 content phase: 20
2012/10/19 16:06:04 [debug] 32002#0: *102 http filename:
"/srv/files/Info.txt"
2012/10/19 16:06:04 [debug] 32002#0: *102 add cleanup: 0000000001F89020
2012/10/19 16:06:04 [debug] 32002#0: *102 http static fd: 38
2012/10/19 16:06:04 [debug] 32002#0: *102 mod_zip: entering header filter
2012/10/19 16:06:04 [debug] 32002#0: *102 uploadprogress error-tracker
error: 0
2012/10/19 16:06:04 [debug] 32002#0: *102 xslt filter header
2012/10/19 16:06:04 [debug] 32002#0: *102 charset: "" > "UTF-8"
2012/10/19 16:06:04 [debug] 32002#0: *102 http output filter
"/files/Info.txt?"
2012/10/19 16:06:04 [debug] 32002#0: *102 http copy filter:
"/files/Info.txt?"
2012/10/19 16:06:04 [debug] 32002#0: *102 read: 38, 0000000001F89250, 1267,
0
2012/10/19 16:06:04 [debug] 32002#0: *102 mod_zip: entering subrequest body
filter
2012/10/19 16:06:04 [debug] 32002#0: *102 mod_zip: No range for subrequest
to satisfy
2012/10/19 16:06:04 [debug] 32002#0: *102 image filter
2012/10/19 16:06:04 [debug] 32002#0: *102 xslt filter body
2012/10/19 16:06:04 [debug] 32002#0: *102 http postpone filter
"/files/Info.txt?" 0000000001F89748
2012/10/19 16:06:04 [debug] 32002#0: *102 write old buf t:0 f:0
0000000000000000, pos 0000000001F35610, size: 107 file: 0, size: 0
2012/10/19 16:06:04 [debug] 32002#0: *102 write new buf t:1 f:1
0000000001F89250, pos 0000000001F89250, size: 1267 file: 0, size: 1267
2012/10/19 16:06:04 [debug] 32002#0: *102 http write filter: l:0 f:0 s:1374
2012/10/19 16:06:04 [debug] 32002#0: *102 http copy filter: 0
"/files/Info.txt?"
2012/10/19 16:06:04 [debug] 32002#0: *102 http finalize request: 0,
"/files/Info.txt?" a:1, c:2
2012/10/19 16:06:04 [debug] 32002#0: *102 http wake parent request:
"/rest/download/stream/507d6aaae4b0be1d4bcd3f8a"
2012/10/19 16:06:04 [debug] 32002#0: *102 http posted request:
"/rest/download/stream/507d6aaae4b0be1d4bcd3f8a"
2012/10/19 16:06:04 [debug] 32002#0: *102 http writer handler:
"/rest/download/stream/507d6aaae4b0be1d4bcd3f8a"
2012/10/19 16:06:04 [debug] 32002#0: *102 http output filter
"/rest/download/stream/507d6aaae4b0be1d4bcd3f8a"
2012/10/19 16:06:04 [debug] 32002#0: *102 http copy filter:
"/rest/download/stream/507d6aaae4b0be1d4bcd3f8a"
2012/10/19 16:06:04 [debug] 32002#0: *102 mod_zip: entering main request
body filter
2012/10/19 16:06:04 [debug] 32002#0: *102 mod_zip: restarting subrequests
2012/10/19 16:06:04 [debug] 32002#0: *102 mod_zip: sending pieces, starting
with piece 10 of total 21
2012/10/19 16:06:04 [debug] 32002#0: *102 mod_zip: no ranges / sending piece
type 0
2012/10/19 16:06:04 [debug] 32002#0: *102 image filter
2012/10/19 16:06:04 [debug] 32002#0: *102 xslt filter body
2012/10/19 16:06:04 [debug] 32002#0: *102 http postpone filter
"/rest/download/stream/507d6aaae4b0be1d4bcd3f8a" 0000000001F89778
2012/10/19 16:06:04 [debug] 32002#0: *102 write old buf t:0 f:0
0000000000000000, pos 0000000001F35610, size: 107 file: 0, size: 0
2012/10/19 16:06:04 [debug] 32002#0: *102 write old buf t:1 f:1
0000000001F89250, pos 0000000001F89250, size: 1267 file: 0, size: 1267
2012/10/19 16:06:04 [debug] 32002#0: *102 write new buf t:0 f:0
0000000000000000, pos 0000000001F897D8, size: 107 file: 0, size: 0
2012/10/19 16:06:04 [debug] 32002#0: *102 http write filter: l:0 f:0 s:1481
2012/10/19 16:06:04 [debug] 32002#0: *102 http write filter limit 0
2012/10/19 16:06:04 [debug] 32002#0: *102 SSL buf copy: 107
2012/10/19 16:06:04 [debug] 32002#0: *102 SSL buf copy: 1267
2012/10/19 16:06:04 [debug] 32002#0: *102 SSL buf copy: 107
2012/10/19 16:06:04 [debug] 32002#0: *102 http write filter
0000000000000000
2012/10/19 16:06:04 [debug] 32002#0: *102 mod_zip: sent 1 pieces, last rc =
-2
2012/10/19 16:06:04 [debug] 32002#0: *102 http copy filter: -2
"/rest/download/stream/507d6aaae4b0be1d4bcd3f8a"
2012/10/19 16:06:04 [debug] 32002#0: *102 http writer output filter: -2,
"/rest/download/stream/507d6aaae4b0be1d4bcd3f8a"
2012/10/19 16:06:04 [debug] 32002#0: *102 event timer: 14, old:
1350652024804, new: 1350652024804
2012/10/19 16:07:04 [debug] 32002#0: *102 event timer del: 14:
1350652024804
2012/10/19 16:07:04 [debug] 32002#0: *102 http run request:
"/rest/download/stream/507d6aaae4b0be1d4bcd3f8a"
2012/10/19 16:07:04 [debug] 32002#0: *102 http writer handler:
"/rest/download/stream/507d6aaae4b0be1d4bcd3f8a"
2012/10/19 16:07:04 [info] 32002#0: *102 client timed out (110: Connection
timed out) while sending response to client, client: 1.1.1.1, server:
srv.dot.com, request: "GET /stream/507d6aaae4b
0be1d4bcd3f8a HTTP/1.1", upstream:
"http://8.8.8.8:28888/rest/download/stream/507d6aaae4b0be1d4bcd3f8a", host:
"srv3.dot.com:444"
2012/10/19 16:07:04 [debug] 32002#0: *102 http finalize request: 408,
"/rest/download/stream/507d6aaae4b0be1d4bcd3f8a" a:1, c:1
2012/10/19 16:07:04 [debug] 32002#0: *102 http terminate request count:1
2012/10/19 16:07:04 [debug] 32002#0: *102 http terminate cleanup count:1
blk:0
2012/10/19 16:07:04 [debug] 32002#0: *102 http posted request:
"/rest/download/stream/507d6aaae4b0be1d4bcd3f8a"
2012/10/19 16:07:04 [debug] 32002#0: *102 http terminate handler count:1
2012/10/19 16:07:04 [debug] 32002#0: *102 http request count:1 blk:0
2012/10/19 16:07:04 [debug] 32002#0: *102 http close request
2012/10/19 16:07:04 [debug] 32002#0: *102 http log handler
2012/10/19 16:07:04 [debug] 32002#0: *102 posix_memalign:
0000000001FC44A0:4096 @16

Дальше чистится память

Очевидно где-то какой-то таймаут. Вопрос где ? И почему по http такого не
наблюдается ?
Заранее благодарен.

Posted at Nginx Forum: http://forum.nginx.org/read.php?21,232039,232039#msg-232039



Подробная информация о списке рассылки nginx-ru