Nginx-ru mailing list archive (nginx-ru@sysoev.ru)
[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
Re: nginx status: reading 100-200, writing 1-5. Как побороть?
- To: nginx-ru@xxxxxxxxx
- Subject: Re: nginx status: reading 100-200, writing 1-5. Как побороть?
- From: "mikhal123" <nginx-forum@xxxxxxxx>
- Date: Tue, 18 Sep 2012 18:26:56 -0400
- Dkim-signature: v=1; a=rsa-sha256; q=dns/txt; c=relaxed/relaxed; d=tigger.jlkhosting.com; s=x; h=Date:Sender:From:References:In-Reply-To:Message-ID:Content-Transfer-Encoding:Content-Type:Subject:To; bh=V8GHEtRXjhDL366MGZfMA8otEtsQAUp8uUmjypV6ZAA=; b=HeZ5v9ss0uOvFamsBItcPcTwEDtV92qhO+gg3fzUqNPgp2g1pq3YoeFuHENZ5BDDR5WiykjntUT6jJHtcTd8ayo2ueLNSgBoMgjYVyK0c5phAankTNK5nuIkQ3opWoZN;
- In-reply-to: <201209190020.50224.ne@vbart.ru>
- References: <201209190020.50224.ne@vbart.ru>
VBart Wrote:
-------------------------------------------------------
> А если посмотреть по access-логу эти айпишники, шлют они только такие
> запросы,
> или хорошие тоже?
При более детальном разборе стало ясно, что такую активность создают (в том
числе) и довольно давно зарегистрированные пользователи сайта. Но я вообще
не понимаю логику работы их клиентов (браузеров). Вот допустим на примере
77.223.64.124. Он начинается запрашивать страничку с сервера (причем не в
первом по порядку соединении, первые 2-3 устанавливаются и "молчат")
2012/09/19 01:32:58 [debug] 48557#0: *28 accept: 77.223.64.124 fd:30
2012/09/19 01:32:58 [debug] 48557#0: *28 event timer add: 30:
3000:1348003981827
2012/09/19 01:32:58 [debug] 48557#0: *28 epoll add event: fd:30 op:1
ev:80000001
2012/09/19 01:32:58 [debug] 48557#0: *28 post event 00007FA86915C218
2012/09/19 01:32:58 [debug] 48557#0: *28 delete posted event
00007FA86915C218
2012/09/19 01:32:58 [debug] 48557#0: *28 malloc: 00000000006FDB80:1296
2012/09/19 01:32:58 [debug] 48557#0: *28 posix_memalign:
00000000006FE0A0:256 @16
2012/09/19 01:32:58 [debug] 48557#0: *28 malloc: 00000000007F6550:16384
2012/09/19 01:32:58 [debug] 48557#0: *28 posix_memalign:
00000000007B75D0:4096 @16
2012/09/19 01:32:58 [debug] 48557#0: *28 http process request line
2012/09/19 01:32:58 [debug] 48557#0: *28 recv: fd:30 804 of 16384
2012/09/19 01:32:58 [debug] 48557#0: *28 http request line: "GET
/some_url.php HTTP/1.1"
2012/09/19 01:32:58 [debug] 48557#0: *28 http uri: "/some_url.php"
2012/09/19 01:32:58 [debug] 48557#0: *28 http args: ""
2012/09/19 01:32:58 [debug] 48557#0: *28 http exten: "php"
2012/09/19 01:32:58 [debug] 48557#0: *28 http process request header line
2012/09/19 01:32:58 [debug] 48557#0: *28 http header: "Host: coolsite.ru"
2012/09/19 01:32:58 [debug] 48557#0: *28 http header: "Connection:
keep-alive"
2012/09/19 01:32:58 [debug] 48557#0: *28 http header: "User-Agent:
Mozilla/5.0 (Windows NT 5.1) AppleWebKit/537.1 (KHTML, like Gecko)
Chrome/21.0.1180.89 Safari/537.1"
2012/09/19 01:32:58 [debug] 48557#0: *28 http header: "Accept:
text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8"
2012/09/19 01:32:58 [debug] 48557#0: *28 http header: "Accept-Encoding:
gzip,deflate,sdch"
2012/09/19 01:32:58 [debug] 48557#0: *28 http header: "Accept-Language:
ru-RU,ru;q=0.8,en-US;q=0.6,en;q=0.4"
2012/09/19 01:32:58 [debug] 48557#0: *28 http header: "Accept-Charset:
windows-1251,utf-8;q=0.7,*;q=0.3"
Ну и дальше идет нормальная обработка этого запроса, и клиенту вроде даже
что-то отправляется. Одновременно с нормальным запросом он открывает еще
тучу соединений и никак их не использует:
2012/09/19 01:32:58 [debug] 48557#0: *31 accept: 77.223.64.124 fd:32
2012/09/19 01:32:58 [debug] 48557#0: *31 event timer add: 32:
3000:1348003981827
2012/09/19 01:32:58 [debug] 48557#0: *31 epoll add event: fd:32 op:1
ev:80000001
2012/09/19 01:32:58 [debug] 48557#0: post event 00007FA86915C010
2012/09/19 01:32:58 [debug] 48557#0: delete posted event 00007FA86915C010
2012/09/19 01:32:58 [debug] 48557#0: accept on 0.0.0.0:80, ready: 0
2012/09/19 01:32:58 [debug] 48557#0: posix_memalign: 00000000006FE2C0:256
@16
2012/09/19 01:32:58 [debug] 48557#0: *32 accept: 77.223.64.124 fd:43
2012/09/19 01:32:58 [debug] 48557#0: *32 event timer add: 43:
3000:1348003981827
2012/09/19 01:32:58 [debug] 48557#0: *32 epoll add event: fd:43 op:1
ev:80000001
2012/09/19 01:32:58 [debug] 48557#0: post event 00007FA86915C010
2012/09/19 01:32:58 [debug] 48557#0: delete posted event 00007FA86915C010
2012/09/19 01:32:58 [debug] 48557#0: accept on 0.0.0.0:80, ready: 0
2012/09/19 01:32:58 [debug] 48557#0: posix_memalign: 00000000006FE3D0:256
@16
2012/09/19 01:32:58 [debug] 48557#0: *33 accept: 77.223.64.124 fd:44
2012/09/19 01:32:58 [debug] 48557#0: *33 event timer add: 44:
3000:1348003981827
2012/09/19 01:32:58 [debug] 48557#0: *33 epoll add event: fd:44 op:1
ev:80000001
2012/09/19 01:32:58 [debug] 48557#0: post event 00007FA86915C010
2012/09/19 01:32:58 [debug] 48557#0: delete posted event 00007FA86915C010
2012/09/19 01:32:58 [debug] 48557#0: accept on 0.0.0.0:80, ready: 0
2012/09/19 01:32:58 [debug] 48557#0: posix_memalign: 00000000006FE4E0:256
@16
2012/09/19 01:32:58 [debug] 48557#0: *34 accept: 77.223.64.124 fd:45
2012/09/19 01:32:58 [debug] 48557#0: *34 event timer add: 45:
3000:1348003981827
2012/09/19 01:32:58 [debug] 48557#0: *34 epoll add event: fd:45 op:1
ev:80000001
2012/09/19 01:32:58 [debug] 48557#0: post event 00007FA86915C010
2012/09/19 01:32:58 [debug] 48557#0: delete posted event 00007FA86915C010
2012/09/19 01:32:58 [debug] 48557#0: accept on 0.0.0.0:80, ready: 0
2012/09/19 01:32:58 [debug] 48557#0: posix_memalign: 00000000006FE5F0:256
@16
2012/09/19 01:32:58 [debug] 48557#0: *35 accept: 77.223.64.124 fd:46
2012/09/19 01:32:58 [debug] 48557#0: *35 event timer add: 46:
3000:1348003981827
2012/09/19 01:32:58 [debug] 48557#0: *35 epoll add event: fd:46 op:1
ev:80000001
2012/09/19 01:32:58 [debug] 48557#0: post event 00007FA86915C010
2012/09/19 01:32:58 [debug] 48557#0: delete posted event 00007FA86915C010
2012/09/19 01:32:58 [debug] 48557#0: accept on 0.0.0.0:80, ready: 0
2012/09/19 01:32:58 [debug] 48557#0: posix_memalign: 00000000006FE700:256
@16
2012/09/19 01:32:58 [debug] 48557#0: *36 accept: 77.223.64.124 fd:47
2012/09/19 01:32:58 [debug] 48557#0: *36 event timer add: 47:
3000:1348003981827
2012/09/19 01:32:58 [debug] 48557#0: *36 epoll add event: fd:47 op:1
ev:80000001
2012/09/19 01:32:58 [debug] 48557#0: post event 00007FA86915C010
2012/09/19 01:32:58 [debug] 48557#0: delete posted event 00007FA86915C010
2012/09/19 01:32:58 [debug] 48557#0: accept on 0.0.0.0:80, ready: 0
2012/09/19 01:32:58 [debug] 48557#0: posix_memalign: 00000000006FE810:256
@16
ну и так далее, еще штук 5-10. затем наступает тишина, и через
client_header_timeout (сейчас 3 секунды, раньше 10 секунд) все эти
соединения отваливаются по таймауту:
2012/09/19 01:33:01 [info] 48557#0: *24 client timed out (110: Connection
timed out) while reading client request line, client: 77.223.64.124, server:
0.0.0.0:80
2012/09/19 01:33:01 [debug] 48557#0: *24 close http connection: 36
2012/09/19 01:33:01 [debug] 48557#0: *24 reusable connection: 0
2012/09/19 01:33:01 [debug] 48557#0: *24 free: 00000000007BA250, unused: 48
2012/09/19 01:33:01 [debug] 48557#0: *25 event timer del: 37: 1348003981827
2012/09/19 01:33:01 [info] 48557#0: *25 client timed out (110: Connection
timed out) while reading client request line, client: 77.223.64.124, server:
0.0.0.0:80
2012/09/19 01:33:01 [debug] 48557#0: *25 close http connection: 37
2012/09/19 01:33:01 [debug] 48557#0: *25 reusable connection: 0
2012/09/19 01:33:01 [debug] 48557#0: *25 free: 00000000007BA360, unused: 48
2012/09/19 01:33:01 [debug] 48557#0: *30 event timer del: 42: 1348003981827
2012/09/19 01:33:01 [info] 48557#0: *30 client timed out (110: Connection
timed out) while reading client request line, client: 77.223.64.124, server:
0.0.0.0:80
2012/09/19 01:33:01 [debug] 48557#0: *30 close http connection: 42
2012/09/19 01:33:01 [debug] 48557#0: *30 reusable connection: 0
2012/09/19 01:33:01 [debug] 48557#0: *30 free: 00000000007B85E0, unused: 48
2012/09/19 01:33:01 [debug] 48557#0: *31 event timer del: 32: 1348003981827
2012/09/19 01:33:01 [info] 48557#0: *31 client timed out (110: Connection
timed out) while reading client request line, client: 77.223.64.124, server:
0.0.0.0:80
2012/09/19 01:33:01 [debug] 48557#0: *31 close http connection: 32
2012/09/19 01:33:01 [debug] 48557#0: *31 reusable connection: 0
2012/09/19 01:33:01 [debug] 48557#0: *31 free: 00000000006FE1B0, unused: 48
2012/09/19 01:33:01 [debug] 48557#0: *32 event timer del: 43: 1348003981827
2012/09/19 01:33:01 [info] 48557#0: *32 client timed out (110: Connection
timed out) while reading client request line, client: 77.223.64.124, server:
0.0.0.0:80
2012/09/19 01:33:01 [debug] 48557#0: *32 close http connection: 43
2012/09/19 01:33:01 [debug] 48557#0: *32 reusable connection: 0
2012/09/19 01:33:01 [debug] 48557#0: *32 free: 00000000006FE2C0, unused: 48
2012/09/19 01:33:01 [debug] 48557#0: *33 event timer del: 44: 1348003981827
2012/09/19 01:33:01 [info] 48557#0: *33 client timed out (110: Connection
timed out) while reading client request line, client: 77.223.64.124, server:
0.0.0.0:80
2012/09/19 01:33:01 [debug] 48557#0: *33 close http connection: 44
2012/09/19 01:33:01 [debug] 48557#0: *33 reusable connection: 0
2012/09/19 01:33:01 [debug] 48557#0: *33 free: 00000000006FE3D0, unused: 48
2012/09/19 01:33:01 [debug] 48557#0: *34 event timer del: 45: 1348003981827
и так далее, все что было открыто ранее. Как я понимаю, именно эти
соединения и влияют на показатель "reading" в nginx_status. Через какое-то
время это опять повторяется.
Разве при нормальной работе браузеры открывают столько соединений и после
этого "молчат" в них? И что это за юзерагент такой - "USER_AGENT:
Mozilla/5.0 (Windows NT 5.1) AppleWebKit/537.1 (KHTML, like Gecko)
Chrome/21.0.1180.89 Safari/537.1"??? В общем ничего не понимаю :)
Posted at Nginx Forum:
http://forum.nginx.org/read.php?21,230818,230828#msg-230828
_______________________________________________
nginx-ru mailing list
nginx-ru@xxxxxxxxx
http://mailman.nginx.org/mailman/listinfo/nginx-ru
|
