On Tue, Oct 27, 2009 at 06:01:24PM +0100, Дмитрий Леоненко wrote:
> Меня в логе смущает следующее:
>
> 009/10/27 11:11:09 [debug] 3049#0: *46935 http cleanup add: 08119954
> 2009/10/27 11:11:09 [debug] 3049#0: *46935 get rr peer, try: 1
> 2009/10/27 11:11:09 [debug] 3049#0: *46935 socket 31
> 2009/10/27 11:11:09 [debug] 3049#0: *46935 connect to 127.0.0.1:80, fd:31
> #46937
> 2009/10/27 11:11:09 [debug] 3049#0: *46935 devpoll add event: fd:31 ev:0001
> 2009/10/27 11:11:09 [debug] 3049#0: *46935 devpoll fd:31 ev:0001 fl:0000
> 2009/10/27 11:11:09 [debug] 3049#0: *46935 devpoll add event: fd:31 ev:0004
> 2009/10/27 11:11:09 [debug] 3049#0: *46935 devpoll fd:31 ev:0004 fl:0000
> 2009/10/27 11:11:09 [debug] 3049#0: *46935 http upstream connect: -2
> 2009/10/27 11:11:09 [debug] 3049#0: *46935 event timer add: 31:
> 60000:2500679241
> 2009/10/27 11:11:18 [debug] 3049#0: *46906 http upstream request:
> "/forumdisplay.php?f=10"
> 2009/10/27 11:11:18 [debug] 3049#0: *46906 http upstream process header
> 2009/10/27 11:11:18 [debug] 3049#0: *46906 malloc: 082C4640:65536
> 2009/10/27 11:11:18 [debug] 3049#0: *46906 recv: fd:28 28689 of 65536
> 2009/10/27 11:11:18 [debug] 3049#0: *46906 http proxy status 200 "200 OK"
> 2009/10/27 11:11:18 [debug] 3049#0: *46906 http proxy header: "Date: Tue, 27
> Oct 2009 08:11:09 GMT"
> 2009/10/27 11:11:18 [debug] 3049#0: *46906 http proxy header: "Server:
> Apache/2.2.8 (Ubuntu) PHP/5.2.4-build1 with Suhosin-Patch"
> 2009/10/27 11:11:18 [debug] 3049#0: *46906 http proxy header: "X-Powered-By:
> PHP/5.2.4-build1"
> 2009/10/27 11:11:18 [debug] 3049#0: *46906 http proxy header:
> "Cache-Control: private"
> 2009/10/27 11:11:18 [debug] 3049#0: *46906 http proxy header: "Pragma:
> private"
> 2009/10/27 11:11:18 [debug] 3049#0: *46906 http proxy header:
> "Content-Encoding: gzip"
> 2009/10/27 11:11:18 [debug] 3049#0: *46906 http proxy header:
> "Content-Length: 28380"
> 2009/10/27 11:11:18 [debug] 3049#0: *46906 http proxy header: "Connection:
> close"
> 2009/10/27 11:11:18 [debug] 3049#0: *46906 malloc: 0811B700:4096
> 2009/10/27 11:11:18 [debug] 3049#0: *46906 http proxy header: "Content-Type:
> text/html; charset=windows-1251"
> 2009/10/27 11:11:18 [debug] 3049#0: *46906 http proxy header done
> 2009/10/27 11:11:18 [debug] 3049#0: *46906 HTTP/1.1 200 OK
>
>
> В аксес логе вот что видно:
>
> 213.186.119.100 - - [27/Oct/2009:11:11:01 +0300] "GET /images/uhr-09.swf
> > HTTP/1.0" 200 1267 "http://www.wizardfox.net/" "Mozilla/5.0 (Macintosh; U;
> > Intel Mac OS X 10.5; en-US; rv:1.9.1.2) Gecko/20090729 Firefox/3.5.2"
> > 213.186.119.100 - - [27/Oct/2009:11:11:01 +0300] "GET
> > /clientscript/kr_scripts/flashmenu.swf?r=1043471 HTTP/1.0" 200 39101 "
> > http://www.wizardfox.net/" "Mozilla/5.0 (Macintosh; U; Intel Mac OS X
> > 10.5; en-US; rv:1.9.1.2) Gecko/20090729 Firefox/3.5.2"
> > 84.242.253.6 - - [27/Oct/2009:11:11:02 +0300] "GET /forumdisplay.php?f=224
> > HTTP/1.1" 200 24136 "
> > http://yandex.ru/yandsearch?text=+Diablo+CAM&from=fx3&clid=46510&lr=225"
> > "Mozilla/5.0 (Windows; U; Windows NT 6.0; ru; rv:1.9.1.3) Gecko/20
> > 090824 Firefox/3.5.3 (.NET CLR 3.5.30729)"
> > 213.186.119.100 - - [27/Oct/2009:11:11:04 +0300] "GET /forum.php HTTP/1.0"
> > 200 25882 "http://www.wizardfox.net/" "Mozilla/5.0 (Macintosh; U; Intel
> > Mac OS X 10.5; en-US; rv:1.9.1.2) Gecko/20090729 Firefox/3.5.2"
> > 92.255.236.14 - - [27/Oct/2009:11:11:04 +0300] "POST /login.php?do=login
> > HTTP/1.1" 200 2670 "http://www.wizardfox.net/showthread.php?t=11518"
> > "Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 5.1; .NET CLR 1.1.4322; .NET
> > CLR 2.0.50727; InfoPath.2)"
> > 213.186.119.100 - - [27/Oct/2009:11:11:29 +0300] "GET
> > /forumdisplay.php?f=10 HTTP/1.0" 200 28380 "
> > http://www.wizardfox.net/forum.php" "Mozilla/5.0 (Macintosh; U; Intel Mac
> > OS X 10.5; en-US; rv:1.9.1.2) Gecko/20090729 Firefox/3.5.2"
> > 92.255.236.14 - - [27/Oct/2009:11:11:29 +0300] "GET /showthread.php?t=11518
> > HTTP/1.1" 200 31347 "-" "Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 5.1;
> > .NET CLR 1.1.4322; .NET CLR 2.0.50727; InfoPath.2)"
> > 77.88.31.246 - - [27/Oct/2009:11:11:29 +0300] "GET
> > /showthread.php?s=4b59d56e0559c2229433983cff8c020c&mode=hybrid&t=10190
> > HTTP/1.1" 200 20015 "-" "Yandex/1.01.001 (compatible; Win16; I)"
> >
>
> Тут видно, что от меня запрос в 11:11:04 а потом следующий проходит только в
> 11:11:29, хотя я тыкал специально непрерывно по ссылкам.
>
> Игорь, какие будут предположения? Что это может быть?
Отладочный лог не самый полный (видимо, debug стоит только на уровне
одного из location'ов), но судя по тому, что есть, в течение 10 секунд
не отвечает Апач: пауза как раз после того, как nginx послал ему запрос.
> 2009/10/27 Дмитрий Леоненко <dmitry.leonenko@gmail.com>
>
> > В аттаче дебаг лог с подвисанием. Я заходил с ip 213.186.119.100
> > Сразу после подвисона дебаг выключил, так что там лишнего почти ничего не
> > должно быть.
--
Игорь Сысоев
http://sysoev.ru
