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

Anton Kuznetsov maybe at arjlover.net
Sun Jul 5 19:59:48 MSD 2009


Гораздо информативнее чем прошлый ответ. ;)

Ну что ж, пересобрал, перезапустил, не просто мне это было... В результате
100мб меньше чем за минуту, не знаю как это предлагалось сделать "в студию",
попробую кусками.

Это grep по *6106

2009/07/05 19:25:23 [debug] 11555#0: *6106 accept: 93.73.181.151 fd:18
2009/07/05 19:25:23 [debug] 11555#0: *6106 event timer add: 18:
30000:1267037422
2009/07/05 19:25:23 [debug] 11555#0: *6106 kevent set event: 18: ft:-1
fl:0025
2009/07/05 19:25:23 [debug] 11555#0: *6106 post event 08124168
2009/07/05 19:25:23 [debug] 11555#0: *6106 delete posted event 08124168
2009/07/05 19:25:23 [debug] 11555#0: *6106 malloc: 080FFC00:660
2009/07/05 19:25:23 [debug] 11555#0: *6106 malloc: 08144000:1024
2009/07/05 19:25:23 [debug] 11555#0: *6106 malloc: 08145000:4096
2009/07/05 19:25:23 [debug] 11555#0: *6106 http process request line
2009/07/05 19:25:23 [debug] 11555#0: *6106 recv: eof:0, avail:269, err:0
2009/07/05 19:25:23 [debug] 11555#0: *6106 recv: fd:18 269 of 1024
2009/07/05 19:25:23 [debug] 11555#0: *6106 http request line: "GET
/film/devchata.cd1.avi HTTP/1.1"
2009/07/05 19:25:23 [debug] 11555#0: *6106 http uri:
"/film/devchata.cd1.avi"
2009/07/05 19:25:23 [debug] 11555#0: *6106 http args: ""
2009/07/05 19:25:23 [debug] 11555#0: *6106 http exten: "avi"
2009/07/05 19:25:23 [debug] 11555#0: *6106 http process request header line
2009/07/05 19:25:23 [debug] 11555#0: *6106 http header: "Host:
ivanka.arjlover.net"
2009/07/05 19:25:23 [debug] 11555#0: *6106 http header: "Accept: */*"
2009/07/05 19:25:23 [debug] 11555#0: *6106 http header: "Referer:
http://ivanka.arjlover.net/film"
2009/07/05 19:25:23 [debug] 11555#0: *6106 http header: "User-Agent:
Mozilla/4.0 (compatible; MSIE 5.00; Windows 98)"
2009/07/05 19:25:23 [debug] 11555#0: *6106 http header: "Range:
bytes=582488556-"
2009/07/05 19:25:23 [debug] 11555#0: *6106 http header: "Pragma: no-cache"
2009/07/05 19:25:23 [debug] 11555#0: *6106 http header: "Cache-Control:
no-cache"
2009/07/05 19:25:23 [debug] 11555#0: *6106 http header: "Connection: close"
2009/07/05 19:25:23 [debug] 11555#0: *6106 http header done
2009/07/05 19:25:23 [debug] 11555#0: *6106 event timer del: 18: 1267037422
2009/07/05 19:25:23 [debug] 11555#0: *6106 generic phase: 0
2009/07/05 19:25:23 [debug] 11555#0: *6106 add cleanup: 0814552C
2009/07/05 19:25:23 [debug] 11555#0: *6106 generic phase: 1
2009/07/05 19:25:23 [debug] 11555#0: *6106 http script regex:
"/info/(.*)\.html"
2009/07/05 19:25:23 [notice] 11555#0: *6106 "/info/(.*)\.html" does not
match "/film/devchata.cd1.avi", client: 93.73.181.151, server:
film.arjlover.net, request: "GET /film/devchata.cd1.avi HTTP/1.1", host: "
ivanka.arjlover.net", referrer: "http://ivanka.arjlover.net/film"
2009/07/05 19:25:23 [debug] 11555#0: *6106 test location: "/"
2009/07/05 19:25:23 [debug] 11555#0: *6106 test location: "cgi/dl.pl"
2009/07/05 19:25:23 [debug] 11555#0: *6106 test location: "no.html"
2009/07/05 19:25:23 [debug] 11555#0: *6106 test location: "nginx_status"
2009/07/05 19:25:23 [debug] 11555#0: *6106 test location: ~
"^/unlim/.*\.(avi|mpg)$"
2009/07/05 19:25:23 [debug] 11555#0: *6106 test location: ~ "/php2/"
2009/07/05 19:25:23 [debug] 11555#0: *6106 test location: ~ "/mrtg/.*"
2009/07/05 19:25:23 [debug] 11555#0: *6106 test location: ~
"\.(html|php|pl)$"
2009/07/05 19:25:23 [debug] 11555#0: *6106 test location: ~
"^/film/.*\.(avi|mpg|gif|jpg)$"
2009/07/05 19:25:23 [debug] 11555#0: *6106 using configuration
"^/film/.*\.(avi|mpg|gif|jpg)$"
2009/07/05 19:25:23 [debug] 11555#0: *6106 http cl:-1 max:1048576
2009/07/05 19:25:23 [debug] 11555#0: *6106 generic phase: 3
2009/07/05 19:25:23 [debug] 11555#0: *6106 http script var
2009/07/05 19:25:23 [debug] 11555#0: *6106 http geo started: 93.73.181.151
2009/07/05 19:25:23 [debug] 11555#0: *6106 http geo: No
2009/07/05 19:25:23 [debug] 11555#0: *6106 http script var: "No"
2009/07/05 19:25:23 [debug] 11555#0: *6106 http script value: "Yes"
2009/07/05 19:25:23 [debug] 11555#0: *6106 http script equal
2009/07/05 19:25:23 [debug] 11555#0: *6106 http script equal: no
2009/07/05 19:25:23 [debug] 11555#0: *6106 http script if
2009/07/05 19:25:23 [debug] 11555#0: *6106 http script if: false
2009/07/05 19:25:23 [debug] 11555#0: *6106 http script var
2009/07/05 19:25:23 [debug] 11555#0: *6106 http script var: ""
2009/07/05 19:25:23 [debug] 11555#0: *6106 http script if
2009/07/05 19:25:23 [debug] 11555#0: *6106 http script if: false
2009/07/05 19:25:23 [debug] 11555#0: *6106 http script var
2009/07/05 19:25:23 [debug] 11555#0: *6106 http script var:
"/film/devchata.cd1.avi"
2009/07/05 19:25:23 [debug] 11555#0: *6106 http script regex: "\.(gif|jpg)$"
2009/07/05 19:25:23 [notice] 11555#0: *6106 "\.(gif|jpg)$" does not match
"/film/devchata.cd1.avi", client: 93.73.181.151, server: film.arjlover.net,
request: "GET /film/devchata.cd1.avi HTTP/1.1", host: "ivanka.arjlover.net",
referrer: "http://ivanka.arjlover.net/film"
2009/07/05 19:25:23 [debug] 11555#0: *6106 http script if
2009/07/05 19:25:23 [debug] 11555#0: *6106 http script if: false
2009/07/05 19:25:23 [debug] 11555#0: *6106 post rewrite phase: 4
2009/07/05 19:25:23 [debug] 11555#0: *6106 generic phase: 5
2009/07/05 19:25:23 [debug] 11555#0: *6106 add cleanup: 081456B8
2009/07/05 19:25:23 [debug] 11555#0: *6106 generic phase: 6
2009/07/05 19:25:23 [debug] 11555#0: *6106 limit_req: -2 4.375
2009/07/05 19:25:23 [warn] 11555#0: *6106 delaying request, excess: 4.375,
by zone "avi", client: 93.73.181.151, server: film.arjlover.net, request:
"GET /film/devchata.cd1.avi HTTP/1.1", host: "ivanka.arjlover.net",
referrer: "http://ivanka.arjlover.net/film"
2009/07/05 19:25:23 [debug] 11555#0: *6106 event timer add: 18:
4375:1267011892
2009/07/05 19:25:27 [debug] 11555#0: *6106 event timer del: 18: 1267011892
2009/07/05 19:25:27 [debug] 11555#0: *6106 http run request:
"/film/devchata.cd1.avi?"
2009/07/05 19:25:27 [debug] 11555#0: *6106 limit_req delay
2009/07/05 19:25:27 [debug] 11555#0: *6106 generic phase: 6
2009/07/05 19:25:27 [debug] 11555#0: *6106 generic phase: 7
2009/07/05 19:25:27 [debug] 11555#0: *6106 add cleanup: 081456D4
2009/07/05 19:25:27 [debug] 11555#0: *6106 limit zone: 90B1E236 2
2009/07/05 19:25:27 [debug] 11555#0: *6106 access phase: 8
2009/07/05 19:25:27 [debug] 11555#0: *6106 access phase: 9
2009/07/05 19:25:27 [debug] 11555#0: *6106 post access phase: 10
2009/07/05 19:25:27 [debug] 11555#0: *6106 content phase: 11
2009/07/05 19:25:27 [debug] 11555#0: *6106 content phase: 12
2009/07/05 19:25:27 [debug] 11555#0: *6106 content phase: 13
2009/07/05 19:25:27 [debug] 11555#0: *6106 http filename:
"/data/film/devchata.cd1.avi"
2009/07/05 19:25:27 [debug] 11555#0: *6106 add cleanup: 08145704
2009/07/05 19:25:27 [debug] 11555#0: *6106 http static fd: 98
2009/07/05 19:25:27 [debug] 11555#0: *6106 http set discard body
2009/07/05 19:25:27 [debug] 11555#0: *6106 HTTP/1.1 206 Partial Content
2009/07/05 19:25:27 [debug] 11555#0: *6106 write new buf t:1 f:0 081458A0,
pos 081458A0, size: 293 file: 0, size: 0
2009/07/05 19:25:27 [debug] 11555#0: *6106 http write filter: l:0 f:0 s:293
2009/07/05 19:25:27 [debug] 11555#0: *6106 http output filter
"/film/devchata.cd1.avi?"
2009/07/05 19:25:27 [debug] 11555#0: *6106 http range body buf: 0-728707072
2009/07/05 19:25:27 [debug] 11555#0: *6106 copy filter:
"/film/devchata.cd1.avi?"
2009/07/05 19:25:27 [debug] 11555#0: *6106 http postpone filter
"/film/devchata.cd1.avi?" 7FBFE890
2009/07/05 19:25:27 [debug] 11555#0: *6106 write old buf t:1 f:0 081458A0,
pos 081458A0, size: 293 file: 0, size: 0
2009/07/05 19:25:27 [debug] 11555#0: *6106 write new buf t:0 f:1 00000000,
pos 00000000, size: 0 file: 582488556, size: 146218516
2009/07/05 19:25:27 [debug] 11555#0: *6106 http write filter: l:1 f:0
s:146218809
2009/07/05 19:25:27 [debug] 11555#0: *6106 http write filter limit 65536
2009/07/05 19:25:27 [debug] 11555#0: *6106 tcp_nopush
2009/07/05 19:25:27 [debug] 11555#0: *6106 sendfile() sent only 65337 bytes
(35: Resource temporarily unavailable)
2009/07/05 19:25:27 [debug] 11555#0: *6106 sendfile: -1, @582488556
65337:69140
2009/07/05 19:25:27 [debug] 11555#0: *6106 http write filter 08145A18
2009/07/05 19:25:27 [debug] 11555#0: *6106 copy filter: -2
"/film/devchata.cd1.avi?"
2009/07/05 19:25:27 [debug] 11555#0: *6106 http finalize request: -2,
"/film/devchata.cd1.avi?" 1
2009/07/05 19:25:27 [debug] 11555#0: *6106 event timer add: 18:
30000:1267041894
2009/07/05 19:25:27 [debug] 11555#0: *6106 kevent set event: 18: ft:-2
fl:0025
2009/07/05 19:25:28 [debug] 11555#0: *6106 post event 08133168
2009/07/05 19:25:28 [debug] 11555#0: *6106 delete posted event 08133168
2009/07/05 19:25:28 [debug] 11555#0: *6106 http run request:
"/film/devchata.cd1.avi?"
2009/07/05 19:25:28 [debug] 11555#0: *6106 http writer handler:
"/film/devchata.cd1.avi?"
2009/07/05 19:25:28 [info] 11555#0: *6106 client timed out (60: Operation
timed out) while sending response to client, client: 93.73.181.151, server:
film.arjlover.net, request: "GET /film/devchata.cd1.avi HTTP/1.1", host: "
ivanka.arjlover.net", referrer: "http://ivanka.arjlover.net/film"
2009/07/05 19:25:28 [debug] 11555#0: *6106 http finalize request: 408,
"/film/devchata.cd1.avi?" 1
2009/07/05 19:25:28 [debug] 11555#0: *6106 http close request
2009/07/05 19:25:28 [debug] 11555#0: *6106 http log handler
2009/07/05 19:25:28 [debug] 11555#0: *6106 http geo started: 93.73.181.151
2009/07/05 19:25:28 [debug] 11555#0: *6106 http geo: ZZ
2009/07/05 19:25:28 [debug] 11555#0: *6106 run cleanup: 08145704
2009/07/05 19:25:28 [debug] 11555#0: *6106 file cleanup: fd:98
2009/07/05 19:25:28 [debug] 11555#0: *6106 run cleanup: 081456D4
2009/07/05 19:25:28 [debug] 11555#0: *6106 free: 08145000, unused: 1393
2009/07/05 19:25:28 [debug] 11555#0: *6106 close http connection: 18
2009/07/05 19:25:28 [debug] 11555#0: *6106 event timer del: 18: 1267041894
2009/07/05 19:25:28 [debug] 11555#0: *6106 free: 08144000
2009/07/05 19:25:28 [debug] 11555#0: *6106 free: 080FFC00
2009/07/05 19:25:28 [debug] 11555#0: *6106 free: 080FB400, unused: 56


Смущает очень большое количество строчек
2009/07/05 19:25:23 [debug] 11555#0: *6111 sendfile() sent only 4096 bytes
(35: Resource temporarily unavailable)
за одну минуту такое случилось 76057 раз. кажется это проблема.

Memory: 4GB

#uname -a
FreeBSD  6.3-STABLE FreeBSD 6.3-STABLE #3: Wed Mar  4 20:08:28 MSK 2009
i386

#sysctl -a|grep sfr
kern.ipc.sfrefer: 0
kern.ipc.sfreadahead: 262144

======= nginx.conf ===
    sendfile       on;
    sendfile_max_chunk 64k;
    postpone_output  1460;

    tcp_nopush     on;
    tcp_nodelay    on;

limit_req_zone $binary_remote_addr  zone=avi:10m   rate=5r/m;

server {
        listen       80 default sndbuf=64k;
======= nginx.conf ===

Антон.

2009/7/2 Maxim Dounin <mdounin at mdounin.ru>

> Hello!
>
> On Thu, Jul 02, 2009 at 06:00:24PM +0200, Anton Kuznetsov wrote:
>
> > access.log:
> > 85.173.24.161 - - [02/Jul/2009:19:52:27 +0400] GET
> > /filmiki/gardemariny.vpered.4of4.avi HTTP/1.0  206 181947
> >
> > error.log debug:
> > 2009/07/02 19:52:27 [info] 3195#0: *77138 client timed out (110:
> Connection
> > timed out) while sending response to client, client: 85.173.24.161,
> server:
> > saltarka.arjlover.net, request: "GET
> /filmiki/gardemariny.vpered.4of4.avi
> > HTTP/1.0", host: "saltarka.arjlover.net", referrer: "
> > http://filmiki.arjlover.net/filmiki/"
> >
> > Из этого можно сделать вывод что коннект уснул в плохом канале? При этом
> > клиент умудряется коннектиться каждую секунду и за выгребать за эту
> секунду
> > килов 200-400.
>
> Из этого можно сделать вывод, что Вы не пересобрали nginx с
> --with-debug.  Там должно быть более сотни строк на самом простом
> запросе.
>
> Maxim Dounin
>
> > Как бы таки остановить этот расстрел сервера коннектами? Этим делом
> > занимаются несколько сотен адресов...
> >
> >
> > 2009/6/24 Maxim Dounin <mdounin at mdounin.ru>
> >
> > > Hello!
> > >
> > > On Tue, Jun 23, 2009 at 07:05:27PM +0200, Anton Kuznetsov wrote:
> > >
> > > > Возвращаясь к проблеме. Как включить debug.log?
> > >
> > > http://lmgtfy.com/?q=nginx+как+включить+debug+log
> > >
> > > Maxim Dounin
> > >
> > > >
> > > > Антон.
> > > >
> > > > 2009/4/3 Maxim Dounin <mdounin at mdounin.ru>
> > > >
> > > > > Hello!
> > > > >
> > > > > On Fri, Apr 03, 2009 at 01:05:50PM +0200, Anton Kuznetsov wrote:
> > > > >
> > > > > > А мне что делать? Мою проблему как патчить? :)
> > > > >
> > > > > Вам уже было сказано что именно вам делать - воспроизвести
> > > > > проблему без limit_req или с limit_req .. nodelay, после чего
> > > > > приносить конфиг и debug log.
> > > > >
> > > > > Maxim Dounin
> > > > >
> > > > > >
> > > > > > 2009/4/3 Maxim Dounin <mdounin at mdounin.ru>
> > > > > >
> > > > > > > Hello!
> > > > > > >
> > > > > > > On Fri, Apr 03, 2009 at 11:03:19AM +0200, Sergey Bondari wrote:
> > > > > > >
> > > > > > > > Hello Maxim,
> > > > > > > >
> > > > > > > >
> > > > > > > > MD> Если используется limit_req - надо либо накатить патч
> > > (пробегал
> > > > > > > > MD> тут давеча), либо использовать limit_req ... nodelay.
> > > > > > > > Патч кстати проблему решил. Один вопрос - этот патч временная
> > > > > заплатка
> > > > > > > > от вас или уже включена в транк? В смысле каждый раз его пока
> > > > > > > > накатывать после апдейта nginx?
> > > > > > >
> > > > > > > Пока - накатывать.
> > > > > > >
> > > > > > > Maxim Dounin
> > > > > > >
> > > > > > >
> > > > > >
> > > > > >
> > > > > > --
> > > > > > Best regards,
> > > > > > Anton Kuznetsov.
> > > > >
> > > > >
> > > >
> > > >
> > > > --
> > > > Best regards,
> > > > Anton Kuznetsov.
> > >
> > >
> >
> >
> > --
> > Best regards,
> > Anton Kuznetsov.
>
>


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


More information about the nginx-ru mailing list