Re: zero size reply (200 0 в л огах)

[Maxim Dounin <mdounin@xxxxxxxxxx>]

Hello!

On Tue, Aug 25, 2009 at 08:59:20PM +0400, Alexander Azarov wrote:

> Добрый день!
>
> Наблюдаю записи в логах со статусом 200 и размером ответа 0. При  
> рассмотрении debug лога обнаружилось две странности. Первая:
>
> 2009/08/25 20:13:16 [info] 17099#0: *1338651 client closed prematurely  
> connection, so upstream conne
> ction is closed too while sending request to upstream, client:  
> 66.249.65.86, server: ***,
>  request: "GET /forum-52 HTTP/1.1", subrequest: "/news.html", u
> pstream: "fastcgi://127.0.0.1:9004", host: "***"
> 2009/08/25 20:13:16 [debug] 17099#0: *1338651 finalize http upstream  
> request: 499
>
> /news.html это SSI вставка. Клиент закрыл соединение, это ОК. Должен был 
> бы получиться статус 499 и он таковой для подзапроса, однако у запроса в 
> логе 200. Это баг или фича? Можно ли как-то в логе получить 499?

Заголовки ответа на основной запрос уходят раньше, чем начинает 
работать SSI.  Именно код ответа из этих заголовков (т.е. отданный 
клиенту) логгируется.

Точно так же для обычного ответа клиент может закрыть соединение 
раньше, чем получит весь ответ.  В этом случае будет код 200 - но 
по размеру отданного будет видно, что клиент забрал не всё.

499 в логе будет только если клиент закрыл соединение до того, как 
ему отправили заголовки.

> Вторая странность. Указанный запрос был от Гугла:
>
> 66.249.65.86 - - [25/Aug/2009:20:13:16 +0400] "GET /forum-52 HTTP/1.1"  
> 200 0 "-" "Mediapartners-Google" 0.027
>
> Получен он был в 20:13:16 и в ту же секунду "client closed connection". С 
> чего бы? Я далек от мысли, что удачно увидел падение гуглобота и, к тому 
> же, видел такие же "client closed connection в ту же секунду" в других 
> debug логах. У меня паранойя или?...

Очень похоже что "Mediapartners-Google" - это такой специальный 
гугловый бот, расчитанный на нагнетание психологической 
напряжённости и стимуляцию психических заболеваний среди админов.

В частности, у себя в логах я вижу:

66.249.65.40 - - [17/Aug/2009:17:50:54 +0400] "GET /index2.php?fold=&fil=655 
HTTP/1.1" 499 0 "-" "Mediapartners-Google" "pravda.zerok.ru" "-" "-"

2009/08/17 17:50:54 [info] 918#0: *1202995 kevent() reported that 
client closed prematurely connection, so upstream connection is 
closed too while sending request to upstream, client: 
66.249.65.40, server: other, request: "GET 
/index2.php?fold=&fil=655 HTTP/1.1", upstream: 
"http://127.0.0.1:80/index2.php?fold=&fil=655";, host: 
"pravda.zerok.ru"

В общем, имеет смысл забить.

Maxim Dounin