Re: ошибка "upstream prematurely closed connection" - обсудим ?

[Maxim Dounin]

Hello!

On Sun, Oct 13, 2019 at 02:18:30PM +0500, Илья Шипицин wrote:

> привет,
> 
> предыстория. видим ошибку в логах. вспоминаем концепцию, что с уровнем
> error логируются ошибки на стороне сервера. считаем, что ошибка
> действительно была. идем к клиенту - у клиента статус 200, ему хорошо, все,
> что он хотел считать, он вычитал. повторяем несколько раз, в большинстве
> случаев ситуация повторяется, в логах ошибка, у клиента все хорошо.
> 
> ок. идем смотреть исходники
> 
> вывод сообщения об ошибке встречается три раза
> 
> ./nginx-1.17.4/src/http/ngx_http_upstream.c:
>  "upstream prematurely closed connection");
> ./nginx-1.17.4/src/http/ngx_http_upstream.c:
>    "upstream prematurely closed connection");
> ./nginx-1.17.4/src/http/ngx_http_upstream.c:
>  "upstream prematurely closed connection");
> 
> в двух случаях запрос завершается статусом 502
> 
> ngx_http_upstream_finalize_request(r, u, NGX_HTTP_BAD_GATEWAY);
> 
> 
> в одном месте - не завершается:
> http://hg.nginx.org/nginx/file/tip/src/http/ngx_http_upstream.c#l2369

Да, если ошибка происходит при чтении заголовка ответа - nginx 
пробует перейти к следующему бэкенду, так как это ещё возможно.  
Что, однако же, не означает, что ошибки нет - она есть.

> собственно, recv в некоторых случаях может выдавать 0 и это не всегда
> ошибка (у нас CentOS 7, возможно, там какая-то своя магия еще, с
> какими-нибудь сетевыми штуками бекпортированными в ядро 3.10)
> 
> man recv
> ...
> "The value 0 may also be returned if the requested number of bytes to
> receive from a stream socket was 0."
> 
> собственно, в этом месте меняем текст. и, чудо, после этого залогированные
> "upstream prematurely closed connection" идеально кореллируют с реальными
> обрывами.
> 
> вопрос - в этом месте действительно стоит логировать ошибку с таким текстом
> ? может поменять уровень на info (или debug), а текст сделать что-то типа
> "zero bytes read from recv" ?

Если recv() возвращает 0 байт - в предположении, что буфер был не 
нулевого размера - то это означает, что соединение закрыто "той 
стороной".  Если это происходит в момент времени, не 
предусмотренный протоколом - то это ошибка, и она логгируется 
соответственно.

-- 
Maxim Dounin
http://mdounin.ru/