Re: Re[8]: Постоянные обрывы коннектов

Anton Kuznetsov maybe at arjlover.net
Thu Jul 16 02:32:58 MSD 2009 

Uniq IP: 386     Established connection:  938
limit_req_zone $binary_remote_addr  zone=avi:10m   rate=2r/m;
По-моему - как до Луны... :)

log:
217.118.90.158 - - [16/Jul/2009:02:02:18 +0400] 40.311 bytes=575302136- GET
/filmiki/mary.poppins.cd2.avi HTTP/1.0 ZZ 206 30216 "Download Master"

Debug:
2009/07/16 02:01:37 [debug] 55481#0: *594615 accept: 217.118.90.158 fd:130
2009/07/16 02:01:37 [debug] 55481#0: *594615 event timer add: 130:
30000:2154811833
2009/07/16 02:01:37 [debug] 55481#0: *594615 kevent set event: 130: ft:-1
fl:0025
2009/07/16 02:01:38 [debug] 55481#0: *594615 post event 2844FD20
2009/07/16 02:01:38 [debug] 55481#0: *594615 delete posted event 2844FD20
2009/07/16 02:01:38 [debug] 55481#0: *594615 malloc: 29030400:660
2009/07/16 02:01:38 [debug] 55481#0: *594615 malloc: 29030800:1024
2009/07/16 02:01:38 [debug] 55481#0: *594615 malloc: 29039000:4096
2009/07/16 02:01:38 [debug] 55481#0: *594615 http process request line
2009/07/16 02:01:38 [debug] 55481#0: *594615 recv: eof:0, avail:424, err:0
2009/07/16 02:01:38 [debug] 55481#0: *594615 recv: fd:130 424 of 1024
2009/07/16 02:01:38 [debug] 55481#0: *594615 http request line: "GET
/filmiki/mary.poppins.cd2.avi HTTP/1.0"
2009/07/16 02:01:38 [debug] 55481#0: *594615 http uri:
"/filmiki/mary.poppins.cd2.avi"
2009/07/16 02:01:38 [debug] 55481#0: *594615 http args: ""
2009/07/16 02:01:38 [debug] 55481#0: *594615 http exten: "avi"
2009/07/16 02:01:38 [debug] 55481#0: *594615 http process request header
line
2009/07/16 02:01:38 [debug] 55481#0: *594615 http header: "User-Agent:
Download Master"
2009/07/16 02:01:38 [debug] 55481#0: *594615 http header: "Cookie:
__utma=17544366.2091389341.1247520403.1247520403.1247520403.1;
__utmz=17544366.1247520403.1.1.utmccn=(referral)|utmcsr=multiki.arjlover.net
|utmcct=/|utmcmd=referral"
2009/07/16 02:01:38 [debug] 55481#0: *594615 http header: "Accept: */*"
2009/07/16 02:01:38 [debug] 55481#0: *594615 http header: "Referer:
http://filmiki.arjlover.net/info/mary.poppins.cd2.avi.html"
2009/07/16 02:01:38 [debug] 55481#0: *594615 http header: "Range:
bytes=575302136-"
2009/07/16 02:01:38 [debug] 55481#0: *594615 http header: "Pragma: no-cache"
2009/07/16 02:01:38 [debug] 55481#0: *594615 http header: "Cache-Control:
no-cache"
2009/07/16 02:01:38 [debug] 55481#0: *594615 http header: "Host:
inka.arjlover.net"
2009/07/16 02:01:38 [debug] 55481#0: *594615 http header done
2009/07/16 02:01:38 [debug] 55481#0: *594615 event timer del: 130:
2154811833
2009/07/16 02:01:38 [debug] 55481#0: *594615 generic phase: 0
2009/07/16 02:01:38 [debug] 55481#0: *594615 add cleanup: 29039598
2009/07/16 02:01:38 [debug] 55481#0: *594615 generic phase: 1
2009/07/16 02:01:38 [debug] 55481#0: *594615 test location: "/"
2009/07/16 02:01:38 [debug] 55481#0: *594615 test location: "50x.html"
2009/07/16 02:01:38 [debug] 55481#0: *594615 test location: "statn"
2009/07/16 02:01:38 [debug] 55481#0: *594615 test location: "no.html"
2009/07/16 02:01:38 [debug] 55481#0: *594615 test location: ~ "/php2/"
2009/07/16 02:01:38 [debug] 55481#0: *594615 test location: ~ "/mrtg/.*"
2009/07/16 02:01:38 [debug] 55481#0: *594615 test location: ~
"\.(html|php|pl)$"
2009/07/16 02:01:38 [debug] 55481#0: *594615 test location: ~
"/(stat|session)/"
2009/07/16 02:01:38 [debug] 55481#0: *594615 test location: ~
"^/(film|filmiki|multiki)/.*\.(avi|mpg|gif|jpg)$"
2009/07/16 02:01:38 [debug] 55481#0: *594615 using configuration
"^/(film|filmiki|multiki)/.*\.(avi|mpg|gif|jpg)$"
2009/07/16 02:01:38 [debug] 55481#0: *594615 http cl:-1 max:1048576
2009/07/16 02:01:38 [debug] 55481#0: *594615 generic phase: 3
2009/07/16 02:01:38 [debug] 55481#0: *594615 http script var
2009/07/16 02:01:38 [debug] 55481#0: *594615 http script var: ""
2009/07/16 02:01:38 [debug] 55481#0: *594615 http script if
2009/07/16 02:01:38 [debug] 55481#0: *594615 http script if: false
2009/07/16 02:01:38 [debug] 55481#0: *594615 http script var
2009/07/16 02:01:38 [debug] 55481#0: *594615 http script var:
"/filmiki/mary.poppins.cd2.avi"
2009/07/16 02:01:38 [debug] 55481#0: *594615 http script regex:
"\.(gif|jpg)$"
2009/07/16 02:01:38 [notice] 55481#0: *594615 "\.(gif|jpg)$" does not match
"/filmiki/mary.poppins.cd2.avi", client: 217.118.90.158, server:
inka.arjlover.net, request: "GET /filmiki/mary.poppins.cd2.avi HTTP/1.0",
host: "inka.arjlover.net", referrer: "
http://filmiki.arjlover.net/info/mary.poppins.cd2.avi.html"
2009/07/16 02:01:38 [debug] 55481#0: *594615 http script if
2009/07/16 02:01:38 [debug] 55481#0: *594615 http script if: false
2009/07/16 02:01:38 [debug] 55481#0: *594615 post rewrite phase: 4
2009/07/16 02:01:38 [debug] 55481#0: *594615 generic phase: 5
2009/07/16 02:01:38 [debug] 55481#0: *594615 add cleanup: 290396A8
2009/07/16 02:01:38 [debug] 55481#0: *594615 generic phase: 6
2009/07/16 02:01:38 [debug] 55481#0: *594615 limit_req: -2 0.308
2009/07/16 02:01:38 [warn] 55481#0: *594615 delaying request, excess: 0.308,
by zone "avi", client: 217.118.90.158, server: inka.arjlover.net, request:
"GET /filmiki/mary.poppins.cd2.avi HTTP/1.0", host: "inka.arjlover.net",
referrer: "http://filmiki.arjlover.net/info/mary.poppins.cd2.avi.html"
2009/07/16 02:01:38 [debug] 55481#0: *594615 event timer add: 130:
308:2154782904
2009/07/16 02:01:38 [debug] 55481#0: *594615 event timer del: 130:
2154782904
2009/07/16 02:01:38 [debug] 55481#0: *594615 http run request:
"/filmiki/mary.poppins.cd2.avi?"
2009/07/16 02:01:38 [debug] 55481#0: *594615 add cleanup: 290396A8
2009/07/16 02:01:38 [debug] 55481#0: *594615 generic phase: 6
2009/07/16 02:01:38 [debug] 55481#0: *594615 limit_req: -2 0.308
2009/07/16 02:01:38 [warn] 55481#0: *594615 delaying request, excess: 0.308,
by zone "avi", client: 217.118.90.158, server: inka.arjlover.net, request:
"GET /filmiki/mary.poppins.cd2.avi HTTP/1.0", host: "inka.arjlover.net",
referrer: "http://filmiki.arjlover.net/info/mary.poppins.cd2.avi.html"
2009/07/16 02:01:38 [debug] 55481#0: *594615 event timer add: 130:
308:2154782904
2009/07/16 02:01:38 [debug] 55481#0: *594615 event timer del: 130:
2154782904
2009/07/16 02:01:38 [debug] 55481#0: *594615 http run request:
"/filmiki/mary.poppins.cd2.avi?"
2009/07/16 02:01:38 [debug] 55481#0: *594615 limit_req delay
2009/07/16 02:01:38 [debug] 55481#0: *594615 generic phase: 6
2009/07/16 02:01:38 [debug] 55481#0: *594615 generic phase: 7
2009/07/16 02:01:38 [debug] 55481#0: *594615 add cleanup: 290396C4
2009/07/16 02:01:38 [debug] 55481#0: *594615 limit zone: 7D873670 2
2009/07/16 02:01:38 [debug] 55481#0: *594615 access phase: 8
2009/07/16 02:01:38 [debug] 55481#0: *594615 access phase: 9
2009/07/16 02:01:38 [debug] 55481#0: *594615 post access phase: 10
2009/07/16 02:01:38 [debug] 55481#0: *594615 content phase: 11
2009/07/16 02:01:38 [debug] 55481#0: *594615 content phase: 12
2009/07/16 02:01:38 [debug] 55481#0: *594615 content phase: 13
2009/07/16 02:01:38 [debug] 55481#0: *594615 content phase: 14
2009/07/16 02:01:38 [debug] 55481#0: *594615 content phase: 15
2009/07/16 02:01:38 [debug] 55481#0: *594615 http filename:
"/data/filmiki/mary.poppins.cd2.avi"
2009/07/16 02:01:38 [debug] 55481#0: *594615 add cleanup: 290396FC
2009/07/16 02:01:38 [debug] 55481#0: *594615 http static fd: 163
2009/07/16 02:01:38 [debug] 55481#0: *594615 http set discard body
2009/07/16 02:01:38 [debug] 55481#0: *594615 HTTP/1.1 206 Partial Content
2009/07/16 02:01:38 [debug] 55481#0: *594615 write new buf t:1 f:0 29039898,
pos 29039898, size: 292 file: 0, size: 0
2009/07/16 02:01:38 [debug] 55481#0: *594615 http write filter: l:0 f:0
s:292
2009/07/16 02:01:38 [debug] 55481#0: *594615 http output filter
"/filmiki/mary.poppins.cd2.avi?"
2009/07/16 02:01:38 [debug] 55481#0: *594615 http range body buf:
0-734515200
2009/07/16 02:01:38 [debug] 55481#0: *594615 copy filter:
"/filmiki/mary.poppins.cd2.avi?"
2009/07/16 02:01:38 [debug] 55481#0: *594615 http postpone filter
"/filmiki/mary.poppins.cd2.avi?" 7FBFE8F0
2009/07/16 02:01:38 [debug] 55481#0: *594615 write old buf t:1 f:0 29039898,
pos 29039898, size: 292 file: 0, size: 0
2009/07/16 02:01:38 [debug] 55481#0: *594615 write new buf t:0 f:1 00000000,
pos 00000000, size: 0 file: 575302136, size: 159213064
2009/07/16 02:01:38 [debug] 55481#0: *594615 http write filter: l:1 f:0
s:159213356
2009/07/16 02:01:38 [debug] 55481#0: *594615 http write filter limit 65536
2009/07/16 02:01:38 [debug] 55481#0: *594615 tcp_nopush
2009/07/16 02:01:38 [debug] 55481#0: *594615 sendfile() sent only 30508
bytes (35: Resource temporarily unavailable)
2009/07/16 02:01:38 [debug] 55481#0: *594615 sendfile: -1, @575302136
30508:67080
2009/07/16 02:01:38 [debug] 55481#0: *594615 http write filter 29039A0C
2009/07/16 02:01:38 [debug] 55481#0: *594615 copy filter: -2
"/filmiki/mary.poppins.cd2.avi?"
2009/07/16 02:01:38 [debug] 55481#0: *594615 http finalize request: -2,
"/filmiki/mary.poppins.cd2.avi?" 1
2009/07/16 02:01:38 [debug] 55481#0: *594615 event timer add: 130:
40000:2154822906
2009/07/16 02:01:38 [debug] 55481#0: *594615 kevent set event: 130: ft:-2
fl:0025
2009/07/16 02:02:18 [debug] 55481#0: *594615 event timer del: 130:
2154822906
2009/07/16 02:02:18 [debug] 55481#0: *594615 http run request:
"/filmiki/mary.poppins.cd2.avi?"
2009/07/16 02:02:18 [debug] 55481#0: *594615 http writer handler:
"/filmiki/mary.poppins.cd2.avi?"
2009/07/16 02:02:18 [info] 55481#0: *594615 client timed out (60: Operation
timed out) while sending response to client, client: 217.118.90.158, server:
inka.arjlover.net, request: "GET /filmiki/mary.poppins.cd2.avi HTTP/1.0",
host: "inka.arjlover.net", referrer: "
http://filmiki.arjlover.net/info/mary.poppins.cd2.avi.html"
2009/07/16 02:02:18 [debug] 55481#0: *594615 http finalize request: 408,
"/filmiki/mary.poppins.cd2.avi?" 1
2009/07/16 02:02:18 [debug] 55481#0: *594615 http close request
2009/07/16 02:02:18 [debug] 55481#0: *594615 http log handler
2009/07/16 02:02:18 [debug] 55481#0: *594615 http geo started:
217.118.90.158
2009/07/16 02:02:18 [debug] 55481#0: *594615 http geo: ZZ
2009/07/16 02:02:18 [debug] 55481#0: *594615 run cleanup: 290396FC
2009/07/16 02:02:18 [debug] 55481#0: *594615 file cleanup: fd:163
2009/07/16 02:02:18 [debug] 55481#0: *594615 run cleanup: 290396C4
2009/07/16 02:02:18 [debug] 55481#0: *594615 free: 29039000, unused: 1211
2009/07/16 02:02:18 [debug] 55481#0: *594615 close http connection: 130
2009/07/16 02:02:18 [debug] 55481#0: *594615 free: 29030800
2009/07/16 02:02:18 [debug] 55481#0: *594615 free: 29030400
2009/07/16 02:02:18 [debug] 55481#0: *594615 free: 2846FF00, unused: 56


Как я понимаю - коннект ушел на удержание, но оборвался через время равное
send_timeout 40s;
Фича? Конфликт двух настроек? Но вылазит только на "Download Master"? Истина
где-то рядом.... :)

Антон.


2009/7/15 Михаил Монашёв <postmaster at softsearch.ru>

> Здравствуйте, Антон.
>
> Залогируй  в  существующем  логе  ещё  два  параметра:  юзерагента   и
> заголовок  Range.  Найди  строчки,  вызывающие  подозрение.  И  в этих
> подозрительных  строчках  возьми  ip  и  по нему отфильтруй всю сессию
> качания  от  начала  и  до конца. И если лог выйдет небольшой, то кинь
> сюда. Если большой, то дай на неё ссылку.
>
>
> P.S.
> Возможный  вывод  -  переполняется  зона.  Посчитай на пике количество
> уникальных  ip,  умнож  на  два  для верности и рассчитай размер зоны.
> Игорь тут как-то писал сколько на один ip тратится памяти в зоне.
>
>
> --
>
> С уважением,
> Михаил Монашёв, SoftSearch.ru
> mailto:postmaster at softsearch.ru
> ICQ# 166233339
> http://michael.mindmix.ru/
> Без бэкапа по жизни.
>
>
>


-- 
Best regards,
Anton Kuznetsov.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://nginx.org/pipermail/nginx-ru/attachments/20090716/047d9027/attachment.html>

More information about the nginx-ru mailing list