Re: [PATCH 1/2] SUNRPC: accept() may return sockets that are still in SYN_RECV

Re: [PATCH 1/2] SUNRPC: accept() may return sockets that are still in SYN_RECV

[Fields Bruce James]

On Tue, Jul 26, 2016 at 04:08:29PM +0000, Trond Myklebust wrote:
> 
> > On Jul 26, 2016, at 11:43, J. Bruce Fields <bfields-uC3wQj2KruNg9hUCZPvPmw@public.gmane.org> wrote:
> > 
> > On Tue, Jul 26, 2016 at 09:51:19AM -0400, Trond Myklebust wrote:
> >> We're seeing traces of the following form:
> >> 
> >> [10952.396347] svc: transport ffff88042ba4a 000 dequeued, inuse=2
> >> [10952.396351] svc: tcp_accept ffff88042ba4 a000 sock ffff88042a6e4c80
> >> [10952.396362] nfsd: connect from 10.2.6.1, port=187
> >> [10952.396364] svc: svc_setup_socket ffff8800b99bcf00
> >> [10952.396368] setting up TCP socket for reading
> >> [10952.396370] svc: svc_setup_socket created ffff8803eb10a000 (inet ffff88042b75b800)
> >> [10952.396373] svc: transport ffff8803eb10a000 put into queue
> >> [10952.396375] svc: transport ffff88042ba4a000 put into queue
> >> [10952.396377] svc: server ffff8800bb0ec000 waiting for data (to = 3600000)
> >> [10952.396380] svc: transport ffff8803eb10a000 dequeued, inuse=2
> >> [10952.396381] svc_recv: found XPT_CLOSE
> >> [10952.396397] svc: svc_delete_xprt(ffff8803eb10a000)
> >> [10952.396398] svc: svc_tcp_sock_detach(ffff8803eb10a000)
> >> [10952.396399] svc: svc_sock_detach(ffff8803eb10a000)
> >> [10952.396412] svc: svc_sock_free(ffff8803eb10a000)
> >> 
> >> i.e. an immediate close of the socket after initialisation.
> > 
> > Interesting, thanks!
> > 
> > So the one thing I don't understand is why this is correct behavior for
> > accept--I thought it wasn't supposed to return a socket until it was
> > fully established.
> 
> inet_accept() appears to allow SYN_RECV:

OK.  Cc'ing netdev just to make sure we didn't overlook anything.

(Also: what were user-visible symptoms?  Mounts failing, or unexpected
delays?)

--b.

> 
> int inet_accept(struct socket *sock, struct socket *newsock, int flags)
> {
>         struct sock *sk1 = sock->sk;
>         int err = -EINVAL;
>         struct sock *sk2 = sk1->sk_prot->accept(sk1, flags, &err);
> 
>         if (!sk2)
>                 goto do_err;
> 
>         lock_sock(sk2);
> 
>         sock_rps_record_flow(sk2);
>         WARN_ON(!((1 << sk2->sk_state) &
>                   (TCPF_ESTABLISHED | TCPF_SYN_RECV |
>                   TCPF_CLOSE_WAIT | TCPF_CLOSE)));
> 
>         sock_graft(sk2, newsock);
> 
>         newsock->state = SS_CONNECTED;
>         err = 0;
>         release_sock(sk2);
> do_err:
>         return err;
> }
--
To unsubscribe from this list: send the line "unsubscribe linux-nfs" in
the body of a message to majordomo-u79uwXL29TY76Z2rM5mHXA@public.gmane.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [PATCH 1/2] SUNRPC: accept() may return sockets that are still in SYN_RECV

[Eric Dumazet]

On Wed, 2016-07-27 at 14:48 -0400, Fields Bruce James wrote:
> On Tue, Jul 26, 2016 at 04:08:29PM +0000, Trond Myklebust wrote:
> > 
> > > On Jul 26, 2016, at 11:43, J. Bruce Fields <bfields-uC3wQj2KruNg9hUCZPvPmw@public.gmane.org> wrote:
> > > 
> > > On Tue, Jul 26, 2016 at 09:51:19AM -0400, Trond Myklebust wrote:
> > >> We're seeing traces of the following form:
> > >> 
> > >> [10952.396347] svc: transport ffff88042ba4a 000 dequeued, inuse=2
> > >> [10952.396351] svc: tcp_accept ffff88042ba4 a000 sock ffff88042a6e4c80
> > >> [10952.396362] nfsd: connect from 10.2.6.1, port=187
> > >> [10952.396364] svc: svc_setup_socket ffff8800b99bcf00
> > >> [10952.396368] setting up TCP socket for reading
> > >> [10952.396370] svc: svc_setup_socket created ffff8803eb10a000 (inet ffff88042b75b800)
> > >> [10952.396373] svc: transport ffff8803eb10a000 put into queue
> > >> [10952.396375] svc: transport ffff88042ba4a000 put into queue
> > >> [10952.396377] svc: server ffff8800bb0ec000 waiting for data (to = 3600000)
> > >> [10952.396380] svc: transport ffff8803eb10a000 dequeued, inuse=2
> > >> [10952.396381] svc_recv: found XPT_CLOSE
> > >> [10952.396397] svc: svc_delete_xprt(ffff8803eb10a000)
> > >> [10952.396398] svc: svc_tcp_sock_detach(ffff8803eb10a000)
> > >> [10952.396399] svc: svc_sock_detach(ffff8803eb10a000)
> > >> [10952.396412] svc: svc_sock_free(ffff8803eb10a000)
> > >> 
> > >> i.e. an immediate close of the socket after initialisation.
> > > 
> > > Interesting, thanks!
> > > 
> > > So the one thing I don't understand is why this is correct behavior for
> > > accept--I thought it wasn't supposed to return a socket until it was
> > > fully established.
> > 
> > inet_accept() appears to allow SYN_RECV:
> 
> OK.  Cc'ing netdev just to make sure we didn't overlook anything.
> 

SYN_RECV after accept() is a TCP Fast Open property I think.

Maybe you are playing with some global TCP Fast Open settings ?


> (Also: what were user-visible symptoms?  Mounts failing, or unexpected
> delays?)
> 
> --b.
> 
> > 
> > int inet_accept(struct socket *sock, struct socket *newsock, int flags)
> > {
> >         struct sock *sk1 = sock->sk;
> >         int err = -EINVAL;
> >         struct sock *sk2 = sk1->sk_prot->accept(sk1, flags, &err);
> > 
> >         if (!sk2)
> >                 goto do_err;
> > 
> >         lock_sock(sk2);
> > 
> >         sock_rps_record_flow(sk2);
> >         WARN_ON(!((1 << sk2->sk_state) &
> >                   (TCPF_ESTABLISHED | TCPF_SYN_RECV |
> >                   TCPF_CLOSE_WAIT | TCPF_CLOSE)));
> > 
> >         sock_graft(sk2, newsock);
> > 
> >         newsock->state = SS_CONNECTED;
> >         err = 0;
> >         release_sock(sk2);
> > do_err:
> >         return err;
> > }


--
To unsubscribe from this list: send the line "unsubscribe linux-nfs" in
the body of a message to majordomo-u79uwXL29TY76Z2rM5mHXA@public.gmane.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [PATCH 1/2] SUNRPC: accept() may return sockets that are still in SYN_RECV

[Trond Myklebust]

Hi Eric,

> On Jul 27, 2016, at 14:59, Eric Dumazet <eric.dumazet@gmail.com> wrote:
> 
> On Wed, 2016-07-27 at 14:48 -0400, Fields Bruce James wrote:
>> On Tue, Jul 26, 2016 at 04:08:29PM +0000, Trond Myklebust wrote:
>>> 
>>>> On Jul 26, 2016, at 11:43, J. Bruce Fields <bfields@fieldses.org> wrote:
>>>> 
>>>> On Tue, Jul 26, 2016 at 09:51:19AM -0400, Trond Myklebust wrote:
>>>>> We're seeing traces of the following form:
>>>>> 
>>>>> [10952.396347] svc: transport ffff88042ba4a 000 dequeued, inuse=2
>>>>> [10952.396351] svc: tcp_accept ffff88042ba4 a000 sock ffff88042a6e4c80
>>>>> [10952.396362] nfsd: connect from 10.2.6.1, port=187
>>>>> [10952.396364] svc: svc_setup_socket ffff8800b99bcf00
>>>>> [10952.396368] setting up TCP socket for reading
>>>>> [10952.396370] svc: svc_setup_socket created ffff8803eb10a000 (inet ffff88042b75b800)
>>>>> [10952.396373] svc: transport ffff8803eb10a000 put into queue
>>>>> [10952.396375] svc: transport ffff88042ba4a000 put into queue
>>>>> [10952.396377] svc: server ffff8800bb0ec000 waiting for data (to = 3600000)
>>>>> [10952.396380] svc: transport ffff8803eb10a000 dequeued, inuse=2
>>>>> [10952.396381] svc_recv: found XPT_CLOSE
>>>>> [10952.396397] svc: svc_delete_xprt(ffff8803eb10a000)
>>>>> [10952.396398] svc: svc_tcp_sock_detach(ffff8803eb10a000)
>>>>> [10952.396399] svc: svc_sock_detach(ffff8803eb10a000)
>>>>> [10952.396412] svc: svc_sock_free(ffff8803eb10a000)
>>>>> 
>>>>> i.e. an immediate close of the socket after initialisation.
>>>> 
>>>> Interesting, thanks!
>>>> 
>>>> So the one thing I don't understand is why this is correct behavior for
>>>> accept--I thought it wasn't supposed to return a socket until it was
>>>> fully established.
>>> 
>>> inet_accept() appears to allow SYN_RECV:
>> 
>> OK.  Cc'ing netdev just to make sure we didn't overlook anything.
>> 
> 
> SYN_RECV after accept() is a TCP Fast Open property I think.
> 
> Maybe you are playing with some global TCP Fast Open settings ?
> 

The Linux kernel client should not be using TCP fast open, but it is possible that some of the other NFSv3 clients we’re using are.
Would a standard knfsd listener respond to a TCP fast open request, or would the default behaviour be to ignore it?

If the default behaviour for the server is to allow fast open, then we do need these patches, IMO.

> 
>> (Also: what were user-visible symptoms?  Mounts failing, or unexpected
>> delays?)
>> 

Connection retry storms on the server.

>> --b.
>> 
>>> 
>>> int inet_accept(struct socket *sock, struct socket *newsock, int flags)
>>> {
>>>        struct sock *sk1 = sock->sk;
>>>        int err = -EINVAL;
>>>        struct sock *sk2 = sk1->sk_prot->accept(sk1, flags, &err);
>>> 
>>>        if (!sk2)
>>>                goto do_err;
>>> 
>>>        lock_sock(sk2);
>>> 
>>>        sock_rps_record_flow(sk2);
>>>        WARN_ON(!((1 << sk2->sk_state) &
>>>                  (TCPF_ESTABLISHED | TCPF_SYN_RECV |
>>>                  TCPF_CLOSE_WAIT | TCPF_CLOSE)));
>>> 
>>>        sock_graft(sk2, newsock);
>>> 
>>>        newsock->state = SS_CONNECTED;
>>>        err = 0;
>>>        release_sock(sk2);
>>> do_err:
>>>        return err;
>>> }
> 
> 

Re: [PATCH 1/2] SUNRPC: accept() may return sockets that are still in SYN_RECV

[Fields Bruce James]

On Wed, Jul 27, 2016 at 07:11:23PM +0000, Trond Myklebust wrote:
> Hi Eric,
> 
> > On Jul 27, 2016, at 14:59, Eric Dumazet <eric.dumazet-Re5JQEeQqe8AvxtiuMwx3w@public.gmane.org> wrote:
> > 
> > On Wed, 2016-07-27 at 14:48 -0400, Fields Bruce James wrote:
> >> On Tue, Jul 26, 2016 at 04:08:29PM +0000, Trond Myklebust wrote:
> >>> 
> >>>> On Jul 26, 2016, at 11:43, J. Bruce Fields <bfields-uC3wQj2KruNg9hUCZPvPmw@public.gmane.org> wrote:
> >>>> 
> >>>> On Tue, Jul 26, 2016 at 09:51:19AM -0400, Trond Myklebust wrote:
> >>>>> We're seeing traces of the following form:
> >>>>> 
> >>>>> [10952.396347] svc: transport ffff88042ba4a 000 dequeued, inuse=2
> >>>>> [10952.396351] svc: tcp_accept ffff88042ba4 a000 sock ffff88042a6e4c80
> >>>>> [10952.396362] nfsd: connect from 10.2.6.1, port=187
> >>>>> [10952.396364] svc: svc_setup_socket ffff8800b99bcf00
> >>>>> [10952.396368] setting up TCP socket for reading
> >>>>> [10952.396370] svc: svc_setup_socket created ffff8803eb10a000 (inet ffff88042b75b800)
> >>>>> [10952.396373] svc: transport ffff8803eb10a000 put into queue
> >>>>> [10952.396375] svc: transport ffff88042ba4a000 put into queue
> >>>>> [10952.396377] svc: server ffff8800bb0ec000 waiting for data (to = 3600000)
> >>>>> [10952.396380] svc: transport ffff8803eb10a000 dequeued, inuse=2
> >>>>> [10952.396381] svc_recv: found XPT_CLOSE
> >>>>> [10952.396397] svc: svc_delete_xprt(ffff8803eb10a000)
> >>>>> [10952.396398] svc: svc_tcp_sock_detach(ffff8803eb10a000)
> >>>>> [10952.396399] svc: svc_sock_detach(ffff8803eb10a000)
> >>>>> [10952.396412] svc: svc_sock_free(ffff8803eb10a000)
> >>>>> 
> >>>>> i.e. an immediate close of the socket after initialisation.
> >>>> 
> >>>> Interesting, thanks!
> >>>> 
> >>>> So the one thing I don't understand is why this is correct behavior for
> >>>> accept--I thought it wasn't supposed to return a socket until it was
> >>>> fully established.
> >>> 
> >>> inet_accept() appears to allow SYN_RECV:
> >> 
> >> OK.  Cc'ing netdev just to make sure we didn't overlook anything.
> >> 
> > 
> > SYN_RECV after accept() is a TCP Fast Open property I think.
> > 
> > Maybe you are playing with some global TCP Fast Open settings ?
> > 
> 
> The Linux kernel client should not be using TCP fast open, but it is possible that some of the other NFSv3 clients we’re using are.
> Would a standard knfsd listener respond to a TCP fast open request, or would the default behaviour be to ignore it?
> 
> If the default behaviour for the server is to allow fast open, then we do need these patches, IMO.

Even if it's not a default, if there's a configuration that allows
accept to return a socket in SYN_RECV state, then knfsd should handle it
gracefully, especially as long as it's this easy.

It'd still be useful to understand why this is happening, though....

--b.
--
To unsubscribe from this list: send the line "unsubscribe linux-nfs" in
the body of a message to majordomo-u79uwXL29TY76Z2rM5mHXA@public.gmane.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html