Welcome! Log In Create A New Profile

Advanced

Re: Fwd: 1.17.5 regression

Maxim Dounin
December 23, 2019 02:30PM
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;


--
Maxim Dounin
http://mdounin.ru/
_______________________________________________
nginx-devel mailing list
nginx-devel@nginx.org
http://mailman.nginx.org/mailman/listinfo/nginx-devel
Subject Author Views Posted

Fwd: 1.17.5 regression

Gábor Boskovits 147 December 16, 2019 09:04AM

Re: Fwd: 1.17.5 regression

Maxim Dounin 30 December 18, 2019 12:26PM

Re: Fwd: 1.17.5 regression

Gábor Boskovits 29 December 18, 2019 12:36PM

Re: Fwd: 1.17.5 regression

ru@nginx.com 28 December 19, 2019 03:46AM

Re: Fwd: 1.17.5 regression

Gábor Boskovits 25 December 19, 2019 04:34AM

Re: Fwd: 1.17.5 regression

Maxim Dounin 27 December 19, 2019 07:46AM

Re: Fwd: 1.17.5 regression

Gábor Boskovits 31 December 19, 2019 09:02AM

Re: Fwd: 1.17.5 regression

Maksim Yevmenkin 33 December 19, 2019 12:02PM

Re: Fwd: 1.17.5 regression

Maxim Dounin 26 December 23, 2019 08:36AM

Re: Fwd: 1.17.5 regression

Maxim Dounin 31 December 23, 2019 02:30PM

Re: Fwd: 1.17.5 regression

Gábor Boskovits 26 December 24, 2019 10:46AM

Re: Fwd: 1.17.5 regression

Maxim Dounin 29 December 24, 2019 11:46AM

Re: Fwd: 1.17.5 regression

Gábor Boskovits 25 December 24, 2019 11:56AM

Re: Fwd: 1.17.5 regression

Maksim Yevmenkin 27 December 24, 2019 12:02PM

Re: Fwd: 1.17.5 regression

Maxim Dounin 30 December 24, 2019 12:28PM

Re: 1.17.5 regression

Sergey Kandaurov 60 December 25, 2019 05:16AM



Sorry, you do not have permission to post/reply in this forum.

Online Users

Guests: 99
Record Number of Users: 6 on February 13, 2018
Record Number of Guests: 421 on December 02, 2018
Powered by nginx      Powered by FreeBSD      PHP Powered      Powered by MariaDB      ipv6 ready