Re: Странный вывод tcp dump и странное поведение nginx.

[Maxim Dounin <mdounin@xxxxxxxxxx>]

Hello!

On Thu, Jul 02, 2009 at 05:46:03PM +0400, J Channel wrote:

> limit_req не используется.
> Nginx теперь 0.8.4.
> Что за поля, в данном примере заполненые цифрами 11841#0: *39557 - не знаю,
> но попытался выделить по этому значению что-то из лога после того, как
> получил их в строчке от fgrep "(110:" error_log
> 
> 2009/07/02 17:30:42 [debug] 11841#0: *39557 http keepalive handler
> 2009/07/02 17:30:42 [debug] 11841#0: *39557 malloc: 0000000006F07570:1024
> 2009/07/02 17:30:42 [debug] 11841#0: *39557 recv: fd:43 -1 of 1024
> 2009/07/02 17:30:42 [debug] 11841#0: *39557 recv() not ready (11: Resource
> temporarily unavailable)
> 2009/07/02 17:30:55 [debug] 11841#0: *39557 http keepalive handler
> 2009/07/02 17:30:55 [debug] 11841#0: *39557 recv: fd:43 120 of 1024
> 2009/07/02 17:30:55 [debug] 11841#0: *39557 malloc: 000000000703C460:1248
> 2009/07/02 17:30:55 [debug] 11841#0: *39557 malloc: 0000000006FDCB80:4096
> 2009/07/02 17:30:55 [debug] 11841#0: *39557 http process request line
> 2009/07/02 17:30:55 [debug] 11841#0: *39557 recv: fd:43 -1 of 904
> 2009/07/02 17:30:55 [debug] 11841#0: *39557 recv() not ready (11: Resource
> temporarily unavailable)
> 2009/07/02 17:31:05 [debug] 11841#0: *39557 http process request line
> 2009/07/02 17:31:05 [debug] 11841#0: *39557 recv: fd:43 120 of 904
> 2009/07/02 17:31:05 [debug] 11841#0: *39557 recv: fd:43 -1 of 784
> 2009/07/02 17:31:05 [debug] 11841#0: *39557 recv() not ready (11: Resource
> temporarily unavailable)
> 2009/07/02 17:31:10 [debug] 11841#0: *39557 http process request line
> 2009/07/02 17:31:10 [debug] 11841#0: *39557 recv: fd:43 120 of 784
> 2009/07/02 17:31:10 [debug] 11841#0: *39557 recv: fd:43 -1 of 664
> 2009/07/02 17:31:10 [debug] 11841#0: *39557 recv() not ready (11: Resource
> temporarily unavailable)
> 2009/07/02 17:31:12 [debug] 11841#0: *39557 event timer del: 43:
> 1246541472473
> 2009/07/02 17:31:12 [debug] 11841#0: *39557 http process request line
> 2009/07/02 17:31:12 [info] 11841#0: *39557 client timed out (110: Connection
> timed out) while reading client request line, client: 194.126.99.178,
> server: www.server.com, request: "GET /site/common/scrpit.sdo?From=10&nig"
> 2009/07/02 17:31:12 [debug] 11841#0: *39557 http close request
> 2009/07/02 17:31:12 [debug] 11841#0: *39557 http log handler
> 2009/07/02 17:31:12 [debug] 11841#0: *39557 free: 0000000006FDCB80, unused:
> 2109
> 2009/07/02 17:31:12 [debug] 11841#0: *39557 close http connection: 43
> 2009/07/02 17:31:12 [debug] 11841#0: *39557 free: 0000000006F07570
> 2009/07/02 17:31:12 [debug] 11841#0: *39557 free: 000000000703C460
> 2009/07/02 17:31:12 [debug] 11841#0: *39557 free: 000000000703FE20, unused:
> 8
> 2009/07/02 17:31:12 [debug] 11841#0: *39557 free: 0000000006F05F30, unused:
> 128
> 
> Странно, что так быстро закрывается соединениние - client_header_timeout по
> умолчанию 60 секунд, а тут и 10 секунд не проходит.


Пока клиент не начал передавать заголовки (в данном случае - 
передаёт собственно строку запроса) - для keepalive соединений 
работает keepalive_timeout.  Он и срабатывает.

Maxim Dounin