Hello!

On Mon, Jan 13, 2020 at 09:39:29AM -0500, yanda.a wrote:

> Да, конечно, единственное что - изменю доменное имя, если вы не против.

Ок, так понятно, что происходит:

> 2020/01/13 02:28:13 [debug] 17855#17855: *29319057 http write filter 00007FF7599D8E48
> 2020/01/13 02:28:13 [debug] 17855#17855: *29319057 gzip in: 0000000000000000
> 2020/01/13 02:28:13 [debug] 17855#17855: *29319057 http copy filter: -2 "/api/epg?from=1578862800&to=1578949199"
> 2020/01/13 02:28:13 [debug] 17855#17855: *29319057 pipe write downstream done
> 2020/01/13 02:28:13 [debug] 17855#17855: *29319057 event timer: 92, old: 7043363034, new: 7043363039
> 2020/01/13 02:28:13 [debug] 17855#17855: *29319057 event timer: 78, old: 7043333034, new: 7043333039
> 2020/01/13 02:28:13 [debug] 17855#17855: *29319057 http upstream exit: 0000000000000000
> 2020/01/13 02:28:13 [debug] 17855#17855: *29319057 finalize http upstream request: 0
> 2020/01/13 02:28:13 [debug] 17855#17855: *29319057 finalize http proxy request
> 2020/01/13 02:28:13 [debug] 17855#17855: *29319057 free rr peer 2 0
> 2020/01/13 02:28:13 [debug] 17855#17855: *29319057 close http upstream connection: 92

Где-то тут общение с бекендом завершено, однако ответ ещё не
полностью отправлен клиенту. В процессе отправки клиенте
закрывает HTTP/2 stream:

> 2020/01/13 02:28:13 [info] 17855#17855: *29319057 client canceled stream 39 while sending to client, client: 176.59.97.91, server: mydomain.info, request: "GET /api/epg?from=1578862800&to=1578949199 HTTP/2.0", upstream: "http://192.168.50.48:8081/api/epg?from=1578862800&to=1578949199", host:"www.mydomain.info", referrer: "https://www.mydomain.info/"

И дальше зовётся ngx_http_test_reading(), который и финализирует
соединение с кодом 499:

> 2020/01/13 02:28:13 [debug] 17855#17855: *29319057 http run request: "/api/epg?from=1578862800&to=1578949199"
> 2020/01/13 02:28:13 [debug] 17855#17855: *29319057 http test reading
> 2020/01/13 02:28:13 [info] 17855#17855: *29319057 client prematurely closed connection while sending to client, client: 176.59.97.91, server: mydomain.info, request: "GET /api/epg?from=1578862800&to=1578949199 HTTP/2.0", upstream: " http://192.168.50.48:8081/api/epg?from=1578862800&to=1578949199", host: "www.mydomain.info", referrer: "https://www.mydomain.info/"
> 2020/01/13 02:28:13 [debug] 17855#17855: *29319057 http finalize request: 499, "/api/epg?from=1578862800&to=1578949199" a:1, c:1
> 2020/01/13 02:28:13 [debug] 17855#17855: *29319057 http terminate request count:1
> 2020/01/13 02:28:13 [debug] 17855#17855: *29319057 http terminate cleanup count:1 blk:0

При этом в функции ngx_http_terminate_request(), которая обновляет
статус запроса тогда и только тогда, когда статус либо ещё не
стоит, либо клиенту вообще ничего не было отправлено. В данном
случае, видимо, за счёт использования HTTP/2 случается ситуация,
когда клиенту вообще ничего не отправлено (вероятно, за счёт
других данных в соединении), и статус таки обновляется на 499.

Ситуация с $upstream_status "-", видимо, получается похожим
образом: если в процессе работы с бекендом клиент отменяет HTTP/2
stream, то у соответствующей этому stream'у структуре соединения
будет проставлен флаг c->error. И если после этого случается
timeout бекенда, то в ngx_http_upstream_next() nginx, увидев
стоящий флаг c->error, не пойдёт на следующий бекенд, а вместо
этого завершит обработку запроса с кодом 499.

То есть я был неправ, получить в логах 499 при использовании
proxy_ignore_client_abort таки можно, хотя и непросто. В простых
случаях это в основном затрагивает HTTP/2, но и в HTTP/1.x можно
получить похожее поведение, например, при использовании
подзапросов.

На практике при использовании proxy_ignore_client_abort это
означает, что работа с бекендом завершена или не начиналась.

Возвращаясь к исходному вопросу: да, текущее поведение выглядит
нормально.

--
Maxim Dounin
http://mdounin.ru/
_______________________________________________
nginx-ru mailing list
nginx-ru@nginx.org
http://mailman.nginx.org/mailman/listinfo/nginx-ru