Fwd: 1.17.5 regression

Gábor Boskovits boskovits at gmail.com
Tue Dec 24 15:45:20 UTC 2019


Hello Maxim,

Maxim Dounin <mdounin at 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 at 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 at 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


More information about the nginx-devel mailing list