Hello Maxim,

Maxim Dounin <mdounin@mdounin.ru> ezt írta (időpont: 2019. dec. 23., H, 20:28):
>
> Hello!
>
> On Wed, Dec 18, 2019 at 08:24:25PM +0300, Maxim Dounin wrote:
>
> > On Mon, Dec 16, 2019 at 03:02:37PM +0100, Gábor Boskovits wrote:
> >
> > > On berlin.guix.gnu.org we observed a regression upon upgrading nginx
> > > to 1.17.5. The problem was, when pipelining request to a proxy using
> > > tls, we suddenly started to get 408 client timeouts, manifesting in
> > > dropped connections. Currently we worked around the issue by
> > > downgrading to 1.17.4. I have collected some information about the
> > > problem here:
> > > https://gitlab.com/g_bor/fix-nginx-tls
> > > It contains the logs from the good and the bad version, a full nginx
> > > config, some info about how nginx was built. I managed to bisect the
> > > problem down to changeset 9d2ad2fb4423, which introduced the problem.
> > > Any help in further debuggin this would be greatly appreciated.
> >
> > Thanks for the report, it indeed looks like a bug introduced
> > in 9d2ad2fb4423.
> >
> > The problem is that c->read->handler is overwritted when switching
> > to the next pipelined request, ngx_ssl_next_read_handler() is not
> > called, and c->read->ready remains not set. I'll take a look how
> > to fix it properly.
>
> Please try the following patch:
>
> # HG changeset patch
> # User Maxim Dounin <mdounin@mdounin.ru>
> # Date 1577129029 -10800
> # Mon Dec 23 22:23:49 2019 +0300
> # Node ID c2dc6bfd2a0bce28618ef96b87fbdb63c6010575
> # Parent 8e64e11aaca02d50649cd2d9b448508f5b268062
> SSL: reworked posted next events.
>
> Introduced in 9d2ad2fb4423 available bytes handling in SSL relied
> on connection read handler being overwritten to set the ready flag
> and the amount of available bytes. This approach is, however, does
> not work properly when connection read handler is changed, for example,
> when switching to a next pipelined request, and can result in unexpected
> connection timeouts, see here:
>
> http://mailman.nginx.org/pipermail/nginx-devel/2019-December/012825.html
>
> Fix is to introduce ngx_event_process_posted_next() instead, which
> will set ready and available regardless of how event handler is set.
>
> diff --git a/src/event/ngx_event.c b/src/event/ngx_event.c
> --- a/src/event/ngx_event.c
> +++ b/src/event/ngx_event.c
> @@ -238,8 +238,6 @@ ngx_process_events_and_timers(ngx_cycle_
> }
>
> if (!ngx_queue_empty(&ngx_posted_next_events)) {
> - ngx_queue_add(&ngx_posted_events, &ngx_posted_next_events);
> - ngx_queue_init(&ngx_posted_next_events);
> timer = 0;
> }
>
> @@ -263,6 +261,7 @@ ngx_process_events_and_timers(ngx_cycle_
> }
>
> ngx_event_process_posted(cycle, &ngx_posted_events);
> + ngx_event_process_posted_next(cycle, &ngx_posted_next_events);
> }
>
>
> diff --git a/src/event/ngx_event_openssl.c b/src/event/ngx_event_openssl.c
> --- a/src/event/ngx_event_openssl.c
> +++ b/src/event/ngx_event_openssl.c
> @@ -43,7 +43,6 @@ static ssize_t ngx_ssl_recv_early(ngx_co
> #endif
> static ngx_int_t ngx_ssl_handle_recv(ngx_connection_t *c, int n);
> static void ngx_ssl_write_handler(ngx_event_t *wev);
> -static void ngx_ssl_next_read_handler(ngx_event_t *rev);
> #ifdef SSL_READ_EARLY_DATA_SUCCESS
> static ssize_t ngx_ssl_write_early(ngx_connection_t *c, u_char *data,
> size_t size);
> @@ -2018,11 +2017,6 @@ ngx_ssl_recv(ngx_connection_t *c, u_char
> c->read->available = 0;
> c->read->ready = 0;
>
> - if (c->ssl->next_read_handler == NULL) {
> - c->ssl->next_read_handler = c->read->handler;
> - c->read->handler = ngx_ssl_next_read_handler;
> - }
> -
> ngx_post_event(c->read, &ngx_posted_next_events);
> }
>
> @@ -2328,31 +2322,6 @@ ngx_ssl_write_handler(ngx_event_t *wev)
> }
>
>
> -static void
> -ngx_ssl_next_read_handler(ngx_event_t *rev)
> -{
> - ngx_connection_t *c;
> -
> - c = rev->data;
> -
> - ngx_log_debug0(NGX_LOG_DEBUG_EVENT, c->log, 0, "SSL next read handler");
> -
> - rev->handler = c->ssl->next_read_handler;
> - c->ssl->next_read_handler = NULL;
> -
> - if (!rev->ready) {
> - rev->ready = 1;
> - rev->available = -1;
> - }
> -
> - if (rev->posted) {
> - ngx_delete_posted_event(rev);
> - }
> -
> - rev->handler(rev);
> -}
> -
> -
> /*
> * OpenSSL has no SSL_writev() so we copy several bufs into our 16K buffer
> * before the SSL_write() call to decrease a SSL overhead.
> diff --git a/src/event/ngx_event_openssl.h b/src/event/ngx_event_openssl.h
> --- a/src/event/ngx_event_openssl.h
> +++ b/src/event/ngx_event_openssl.h
> @@ -86,7 +86,6 @@ struct ngx_ssl_connection_s {
>
> ngx_event_handler_pt saved_read_handler;
> ngx_event_handler_pt saved_write_handler;
> - ngx_event_handler_pt next_read_handler;
>
> u_char early_buf;
>
> diff --git a/src/event/ngx_event_posted.c b/src/event/ngx_event_posted.c
> --- a/src/event/ngx_event_posted.c
> +++ b/src/event/ngx_event_posted.c
> @@ -34,3 +34,29 @@ ngx_event_process_posted(ngx_cycle_t *cy
> ev->handler(ev);
> }
> }
> +
> +
> +void
> +ngx_event_process_posted_next(ngx_cycle_t *cycle, ngx_queue_t *posted)
> +{
> + ngx_queue_t *q;
> + ngx_event_t *ev;
> +
> + while (!ngx_queue_empty(posted)) {
> +
> + q = ngx_queue_head(posted);
> + ev = ngx_queue_data(q, ngx_event_t, queue);
> +
> + ngx_log_debug1(NGX_LOG_DEBUG_EVENT, cycle->log, 0,
> + "posted next event %p", ev);
> +
> + ngx_delete_posted_event(ev);
> +
> + if (!ev->ready) {
> + ev->ready = 1;
> + ev->available = -1;
> + }
> +
> + ev->handler(ev);
> + }
> +}
> diff --git a/src/event/ngx_event_posted.h b/src/event/ngx_event_posted.h
> --- a/src/event/ngx_event_posted.h
> +++ b/src/event/ngx_event_posted.h
> @@ -39,6 +39,7 @@
>
>
> void ngx_event_process_posted(ngx_cycle_t *cycle, ngx_queue_t *posted);
> +void ngx_event_process_posted_next(ngx_cycle_t *cycle, ngx_queue_t *posted);
>
>
> extern ngx_queue_t ngx_posted_accept_events;
>
Thanks for having a look at this. I will coordinate with others as
when can we schedule a service restart.
I will report back with the results soon.

I wish you a merry christmas, and thanks for the great work all around the year!

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


Best regards,
g_bor
--
OpenPGP Key Fingerprint: 7988:3B9F:7D6A:4DBF:3719:0367:2506:A96C:CF63:0B21
_______________________________________________
nginx-devel mailing list
nginx-devel@nginx.org
http://mailman.nginx.org/mailman/listinfo/nginx-devel