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"??? В общем ничего не понимаю :)
