[nginx] QUIC: "handshake_timeout" configuration parameter.

[Roman Arutyunyan]

Hello Vladimir,

On Mon, Apr 08, 2024 at 03:03:27PM +0300, Vladimir Homutov via nginx-devel wrote:
> On Fri, Sep 22, 2023 at 03:36:25PM +0000, Roman Arutyunyan wrote:
> > details:   https://hg.nginx.org/nginx/rev/ad3d34ddfdcc
> > branches:
> > changeset: 9158:ad3d34ddfdcc
> > user:      Roman Arutyunyan <arut at nginx.com>
> > date:      Wed Sep 13 17:59:37 2023 +0400
> > description:
> > QUIC: "handshake_timeout" configuration parameter.
> >
> > Previously QUIC did not have such parameter and handshake duration was
> > controlled by HTTP/3.  However that required creating and storing HTTP/3
> > session on first client datagram.  Apparently there's no convenient way to
> > store the session object until QUIC handshake is complete.  In the followup
> > patches session creation will be postponed to init() callback.
> >
> 
> [...]
> 
> > diff -r daf8f5ba23d8 -r ad3d34ddfdcc src/event/quic/ngx_event_quic.c
> > --- a/src/event/quic/ngx_event_quic.c	Fri Sep 01 20:31:46 2023 +0400
> > +++ b/src/event/quic/ngx_event_quic.c	Wed Sep 13 17:59:37 2023 +0400
> > @@ -211,6 +211,8 @@ ngx_quic_run(ngx_connection_t *c, ngx_qu
> >      qc = ngx_quic_get_connection(c);
> >
> >      ngx_add_timer(c->read, qc->tp.max_idle_timeout);
> > +    ngx_add_timer(&qc->close, qc->conf->handshake_timeout);
> > +
> 
> It looks like I've hit an issue with early data in such case.
> See the attached patch with details.

Indeed, there's an issue there.

> While there, I suggest a little debug improvement to better track
> stream and their parent connections.
> 
> 

> # HG changeset patch
> # User Vladimir Khomutov <vl at wbsrv.ru>
> # Date 1712576340 -10800
> #      Mon Apr 08 14:39:00 2024 +0300
> # Node ID 6e79f4ec40ed1c1ffec6a46b453051c01e556610
> # Parent  99e7050ac886f7c70a4048691e46846b930b1e28
> QUIC: fixed close timer processing with early data.
> 
> The ngx_quic_run() function uses qc->close timer to limit the handshake
> duration.  Normally it is removed by ngx_quic_do_init_streams() which is
> called once when we are done with initial SSL processing.
> 
> The problem happens when the client sends early data and streams are
> initialized in the ngx_quic_run() -> ngx_quic_handle_datagram() call.
> The order of set/remove timer calls is now reversed; the close timer is
> set up and the timer fires when assigned, starting the unexpected connection
> close process.
> 
> The patch moves timer cancelling right before the place where the stream
> initialization flag is tested, thus making it work with early data.
> 
> The issue was introduced in ad3d34ddfdcc.
> 
> diff --git a/src/event/quic/ngx_event_quic_streams.c b/src/event/quic/ngx_event_quic_streams.c
> --- a/src/event/quic/ngx_event_quic_streams.c
> +++ b/src/event/quic/ngx_event_quic_streams.c
> @@ -575,6 +575,10 @@ ngx_quic_init_streams(ngx_connection_t *
>  
>      qc = ngx_quic_get_connection(c);
>  
> +    if (!qc->closing && qc->close.timer_set) {
> +        ngx_del_timer(&qc->close);
> +    }
> +
>      if (qc->streams.initialized) {
>          return NGX_OK;
>      }
> @@ -630,10 +634,6 @@ ngx_quic_do_init_streams(ngx_connection_
>  
>      qc->streams.initialized = 1;
>  
> -    if (!qc->closing && qc->close.timer_set) {
> -        ngx_del_timer(&qc->close);
> -    }
> -
>      return NGX_OK;
>  }

This assumes that ngx_quic_init_streams() is always called on handshake end,
even if not needed.  This is true now, but it's not something we can to rely on.

Also, we probably don't need to limit handshake duration after streams are
initialized.  Application level will set the required keepalive timeout for
this.  Also, we need to include OCSP validation time in handshake timeout,
which your removed.

I assume a simpler solution would be not to set the timer in ngx_quic_run()
if streams are already initialized.

> # HG changeset patch
> # User Vladimir Khomutov <vl at wbsrv.ru>
> # Date 1712575741 -10800
> #      Mon Apr 08 14:29:01 2024 +0300
> # Node ID d9b80de50040bb8ac2a7e193971d1dfeb579cfc9
> # Parent  6e79f4ec40ed1c1ffec6a46b453051c01e556610
> QUIC: added debug logging of stream creation.
> 
> Currently, it is hard to associate stream connection number with its parent
> connection.  The typical case is to identify QUIC connection number given
> some user-visible URI (which occurs in request stream).
> 
> The patch adds the debug log message which reports about stream creation in
> the stream log and also shows the parent connection number.
> 
> diff --git a/src/event/quic/ngx_event_quic_streams.c b/src/event/quic/ngx_event_quic_streams.c
> --- a/src/event/quic/ngx_event_quic_streams.c
> +++ b/src/event/quic/ngx_event_quic_streams.c
> @@ -805,6 +805,10 @@ ngx_quic_create_stream(ngx_connection_t 
>  
>      ngx_rbtree_insert(&qc->streams.tree, &qs->node);
>  
> +    ngx_log_debug2(NGX_LOG_DEBUG_EVENT, sc->log, 0,
> +                   "quic stream id:0x%xL created in connection *%uA", id,
> +                   c->log->connection);
> +
>      return qs;
>  }
>  

> _______________________________________________
> nginx-devel mailing list
> nginx-devel at nginx.org
> https://mailman.nginx.org/mailman/listinfo/nginx-devel


--
Roman Arutyunyan