Re: [PATCH] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

Re: [PATCH] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Ian Campbell]

[-- Attachment #1: Type: text/plain, Size: 2233 bytes --]

On Sat, 2008-11-01 at 09:41 -0400, Trond Myklebust wrote:
> On Sat, 2008-11-01 at 11:45 +0000, Ian Campbell wrote:
> > On Mon, 2008-10-20 at 07:27 +0100, Ian Campbell wrote:
> > > So far I have bisected down to this range and am currently testing
> > > acee478 which has been up for >4days.
> > 
> > Another update. It has now bisected down to a small range 
> > 
> > 7272dcd31d56580dee7693c21e369fd167e137fe SUNRPC: xprt_autoclose() should not call xprt_disconnect()
> > e06799f958bf7f9f8fae15f0c6f519953fb0257c SUNRPC: Use shutdown() instead of close() when disconnecting a TCP socket
> > ef80367071dce7d2533e79ae8f3c84ec42708dc8 SUNRPC: TCP clear XPRT_CLOSE_WAIT when the socket is closed for writes
> > 3b948ae5be5e22532584113e2e02029519bbad8f SUNRPC: Allow the client to detect if the TCP connection is closed
> > 67a391d72ca7efb387c30ec761a487e50a3ff085 SUNRPC: Fix TCP rebinding logic
> > 66af1e558538137080615e7ad6d1f2f80862de01 SUNRPC: Fix a race in xs_tcp_state_change()
> > 
> > I'm currently testing 3b948ae5be5e22532584113e2e02029519bbad8f.
> > 
> > 7272dcd31d56580dee7693c21e369fd167e137fe repro'd in half a day while
> > ef818a28fac9bd214e676986d8301db0582b92a9 (parent of
> > 66af1e558538137080615e7ad6d1f2f80862de01) survived for 7 days.

According to bisect:

e06799f958bf7f9f8fae15f0c6f519953fb0257c is first bad commit
commit e06799f958bf7f9f8fae15f0c6f519953fb0257c
Author: Trond Myklebust <Trond.Myklebust@netapp.com>
Date:   Mon Nov 5 15:44:12 2007 -0500

    SUNRPC: Use shutdown() instead of close() when disconnecting a TCP socket
    
    By using shutdown() rather than close() we allow the RPC client to wait
    for the TCP close handshake to complete before we start trying to reconnect
    using the same port.
    We use shutdown(SHUT_WR) only instead of shutting down both directions,
    however we wait until the server has closed the connection on its side.
    
    Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com>

I've started testing 2.6.26 + revert. It's been a long while since I
started this process so I'll also have a go at an up to date version.

Cheers,
Ian.
-- 
Ian Campbell

By failing to prepare, you are preparing to fail.

[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 197 bytes --]

Re: [PATCH] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Trond Myklebust]

On Tue, 2008-11-25 at 07:09 +0000, Ian Campbell wrote:
> On Sat, 2008-11-01 at 09:41 -0400, Trond Myklebust wrote:
> > On Sat, 2008-11-01 at 11:45 +0000, Ian Campbell wrote:
> > > On Mon, 2008-10-20 at 07:27 +0100, Ian Campbell wrote:
> > > > So far I have bisected down to this range and am currently testing
> > > > acee478 which has been up for >4days.
> > > 
> > > Another update. It has now bisected down to a small range 
> > > 
> > > 7272dcd31d56580dee7693c21e369fd167e137fe SUNRPC: xprt_autoclose() should not call xprt_disconnect()
> > > e06799f958bf7f9f8fae15f0c6f519953fb0257c SUNRPC: Use shutdown() instead of close() when disconnecting a TCP socket
> > > ef80367071dce7d2533e79ae8f3c84ec42708dc8 SUNRPC: TCP clear XPRT_CLOSE_WAIT when the socket is closed for writes
> > > 3b948ae5be5e22532584113e2e02029519bbad8f SUNRPC: Allow the client to detect if the TCP connection is closed
> > > 67a391d72ca7efb387c30ec761a487e50a3ff085 SUNRPC: Fix TCP rebinding logic
> > > 66af1e558538137080615e7ad6d1f2f80862de01 SUNRPC: Fix a race in xs_tcp_state_change()
> > > 
> > > I'm currently testing 3b948ae5be5e22532584113e2e02029519bbad8f.
> > > 
> > > 7272dcd31d56580dee7693c21e369fd167e137fe repro'd in half a day while
> > > ef818a28fac9bd214e676986d8301db0582b92a9 (parent of
> > > 66af1e558538137080615e7ad6d1f2f80862de01) survived for 7 days.
> 
> According to bisect:
> 
> e06799f958bf7f9f8fae15f0c6f519953fb0257c is first bad commit
> commit e06799f958bf7f9f8fae15f0c6f519953fb0257c
> Author: Trond Myklebust <Trond.Myklebust@netapp.com>
> Date:   Mon Nov 5 15:44:12 2007 -0500
> 
>     SUNRPC: Use shutdown() instead of close() when disconnecting a TCP socket
>     
>     By using shutdown() rather than close() we allow the RPC client to wait
>     for the TCP close handshake to complete before we start trying to reconnect
>     using the same port.
>     We use shutdown(SHUT_WR) only instead of shutting down both directions,
>     however we wait until the server has closed the connection on its side.
>     
>     Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com>
> 
> I've started testing 2.6.26 + revert. It's been a long while since I
> started this process so I'll also have a go at an up to date version.
> 
> Cheers,

That would indicate that the server is failing to close the TCP
connection when the client closes on its end.

Could you remind me what server you are using? Also, does 'netstat -t'
show connections that are stuck in the CLOSE_WAIT state when you see the
hang?

Trond

Re: [PATCH] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Ian Campbell]

On Tue, 2008-11-25 at 08:28 -0500, Trond Myklebust wrote:
> On Tue, 2008-11-25 at 07:09 +0000, Ian Campbell wrote:
> > On Sat, 2008-11-01 at 09:41 -0400, Trond Myklebust wrote:
> > > On Sat, 2008-11-01 at 11:45 +0000, Ian Campbell wrote:
> > > > On Mon, 2008-10-20 at 07:27 +0100, Ian Campbell wrote:
> > > > > So far I have bisected down to this range and am currently testing
> > > > > acee478 which has been up for >4days.
> > > > 
> > > > Another update. It has now bisected down to a small range 
> > > > 
> > > > 7272dcd31d56580dee7693c21e369fd167e137fe SUNRPC: xprt_autoclose() should not call xprt_disconnect()
> > > > e06799f958bf7f9f8fae15f0c6f519953fb0257c SUNRPC: Use shutdown() instead of close() when disconnecting a TCP socket
> > > > ef80367071dce7d2533e79ae8f3c84ec42708dc8 SUNRPC: TCP clear XPRT_CLOSE_WAIT when the socket is closed for writes
> > > > 3b948ae5be5e22532584113e2e02029519bbad8f SUNRPC: Allow the client to detect if the TCP connection is closed
> > > > 67a391d72ca7efb387c30ec761a487e50a3ff085 SUNRPC: Fix TCP rebinding logic
> > > > 66af1e558538137080615e7ad6d1f2f80862de01 SUNRPC: Fix a race in xs_tcp_state_change()
> > > > 
> > > > I'm currently testing 3b948ae5be5e22532584113e2e02029519bbad8f.
> > > > 
> > > > 7272dcd31d56580dee7693c21e369fd167e137fe repro'd in half a day while
> > > > ef818a28fac9bd214e676986d8301db0582b92a9 (parent of
> > > > 66af1e558538137080615e7ad6d1f2f80862de01) survived for 7 days.
> > 
> > According to bisect:
> > 
> > e06799f958bf7f9f8fae15f0c6f519953fb0257c is first bad commit
> > commit e06799f958bf7f9f8fae15f0c6f519953fb0257c
> > Author: Trond Myklebust <Trond.Myklebust@netapp.com>
> > Date:   Mon Nov 5 15:44:12 2007 -0500
> > 
> >     SUNRPC: Use shutdown() instead of close() when disconnecting a TCP socket
> >     
> >     By using shutdown() rather than close() we allow the RPC client to wait
> >     for the TCP close handshake to complete before we start trying to reconnect
> >     using the same port.
> >     We use shutdown(SHUT_WR) only instead of shutting down both directions,
> >     however we wait until the server has closed the connection on its side.
> >     
> >     Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com>
> > 
> > I've started testing 2.6.26 + revert. It's been a long while since I
> > started this process so I'll also have a go at an up to date version.
> > 
> > Cheers,
> 
> That would indicate that the server is failing to close the TCP
> connection when the client closes on its end.
> 
> Could you remind me what server you are using?

2.6.25-2-486 which is a Debian package from backports.org, changelog
indicates that it contains 2.6.25.7.

> Also, does 'netstat -t'
> show connections that are stuck in the CLOSE_WAIT state when you see the
> hang?

I'd have to wait for it to reproduce again to be 100% sure but according
to http://lkml.indiana.edu/hypermail/linux/kernel/0808.3/0120.html
I was seeing connections in FIN_WAIT2 but not CLOSE_WAIT.

Ian.

-- 
Ian Campbell
Current Noise: Diamond Head - It's Electric

"The only real way to look younger is not to be born so soon."
		-- Charles Schulz, "Things I've Had to Learn Over and
		   Over and Over"

Re: [PATCH] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Trond Myklebust]

On Tue, 2008-11-25 at 13:38 +0000, Ian Campbell wrote:
> > That would indicate that the server is failing to close the TCP
> > connection when the client closes on its end.
> > 
> > Could you remind me what server you are using?
> 
> 2.6.25-2-486 which is a Debian package from backports.org, changelog
> indicates that it contains 2.6.25.7.

Hmm... It should normally close sockets when the state changes. There
might be a race, though...

> > Also, does 'netstat -t'
> > show connections that are stuck in the CLOSE_WAIT state when you see the
> > hang?
> 
> I'd have to wait for it to reproduce again to be 100% sure but according
> to http://lkml.indiana.edu/hypermail/linux/kernel/0808.3/0120.html
> I was seeing connections in FIN_WAIT2 but not CLOSE_WAIT.

That would be on the client side. I'm talking about the server.

Cheers
  Trond

Re: [PATCH] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Ian Campbell]

On Tue, 2008-11-25 at 08:57 -0500, Trond Myklebust wrote:
> On Tue, 2008-11-25 at 13:38 +0000, Ian Campbell wrote:
> > > That would indicate that the server is failing to close the TCP
> > > connection when the client closes on its end.
> > > 
> > > Could you remind me what server you are using?
> > 
> > 2.6.25-2-486 which is a Debian package from backports.org, changelog
> > indicates that it contains 2.6.25.7.
> 
> Hmm... It should normally close sockets when the state changes. There
> might be a race, though...
> 
> > > Also, does 'netstat -t'
> > > show connections that are stuck in the CLOSE_WAIT state when you see the
> > > hang?
> > 
> > I'd have to wait for it to reproduce again to be 100% sure but according
> > to http://lkml.indiana.edu/hypermail/linux/kernel/0808.3/0120.html
> > I was seeing connections in FIN_WAIT2 but not CLOSE_WAIT.
> 
> That would be on the client side. I'm talking about the server.

Ah, OK. I'll abort my current test of 2.6.26+revert and wait for a repro
so I can netstat the server, give me a couple of days...

Ian.
-- 
Ian Campbell

It is more rational to sacrifice one life than six.
		-- Spock, "The Galileo Seven", stardate 2822.3

Re: [PATCH] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Ian Campbell]

[-- Attachment #1: Type: text/plain, Size: 5264 bytes --]

On Tue, 2008-11-25 at 14:04 +0000, Ian Campbell wrote:
> On Tue, 2008-11-25 at 08:57 -0500, Trond Myklebust wrote:
> > On Tue, 2008-11-25 at 13:38 +0000, Ian Campbell wrote:
> > > > That would indicate that the server is failing to close the TCP
> > > > connection when the client closes on its end.
> > > > 
> > > > Could you remind me what server you are using?
> > > 
> > > 2.6.25-2-486 which is a Debian package from backports.org, changelog
> > > indicates that it contains 2.6.25.7.
> > 
> > Hmm... It should normally close sockets when the state changes. There
> > might be a race, though...
> > 
> > > > Also, does 'netstat -t'
> > > > show connections that are stuck in the CLOSE_WAIT state when you see the
> > > > hang?
> > > 
> > > I'd have to wait for it to reproduce again to be 100% sure but according
> > > to http://lkml.indiana.edu/hypermail/linux/kernel/0808.3/0120.html
> > > I was seeing connections in FIN_WAIT2 but not CLOSE_WAIT.
> > 
> > That would be on the client side. I'm talking about the server.
> 
> Ah, OK. I'll abort my current test of 2.6.26+revert and wait for a repro
> so I can netstat the server, give me a couple of days...

So on the server I see the following. 192.168.1.4 is the problematic
client and 192.168.1.6 is the server.

Maybe not interesting but 192.168.1.5 also uses NFS for my $HOME and
runs 2.6.26 with no lockups.

# netstat -t -n
Active Internet connections (w/o servers)
Proto Recv-Q Send-Q Local Address           Foreign Address         State      
tcp        1      0 192.168.1.6:2049        192.168.1.4:723         CLOSE_WAIT 
tcp        1      0 192.168.1.6:2049        192.168.1.4:920         CLOSE_WAIT 
tcp        1      0 192.168.1.6:2049        192.168.1.4:890         CLOSE_WAIT 
tcp        1      0 192.168.1.6:2049        192.168.1.4:698         CLOSE_WAIT 
tcp        1      0 192.168.1.6:2049        192.168.1.4:705         CLOSE_WAIT 
tcp        1      0 192.168.1.6:2049        192.168.1.4:943         CLOSE_WAIT 
tcp        1      0 192.168.1.6:2049        192.168.1.4:915         CLOSE_WAIT 
tcp        0      0 192.168.1.6:2049        192.168.1.5:783         ESTABLISHED
tcp        1      0 192.168.1.6:2049        192.168.1.4:998         CLOSE_WAIT 
tcp        1      0 192.168.1.6:2049        192.168.1.4:758         CLOSE_WAIT 
tcp        1      0 192.168.1.6:2049        192.168.1.4:955         CLOSE_WAIT 
tcp        1      0 192.168.1.6:2049        192.168.1.4:845         CLOSE_WAIT 
tcp        1      0 192.168.1.6:2049        192.168.1.4:827         CLOSE_WAIT 
tcp        0      0 192.168.1.6:58464       128.31.0.36:80          ESTABLISHED
tcp        1      0 192.168.1.6:2049        192.168.1.4:754         CLOSE_WAIT 
tcp        1      0 192.168.1.6:2049        192.168.1.4:837         CLOSE_WAIT 
tcp        1      0 192.168.1.6:2049        192.168.1.4:918         CLOSE_WAIT 
tcp        1      0 192.168.1.6:2049        192.168.1.4:865         CLOSE_WAIT 
tcp        0      0 192.168.1.6:48343       192.168.1.5:832         ESTABLISHED
tcp        1      0 192.168.1.6:2049        192.168.1.4:840         CLOSE_WAIT 
tcp        1      0 192.168.1.6:2049        192.168.1.4:883         CLOSE_WAIT 
tcp        1      0 192.168.1.6:2049        192.168.1.4:785         CLOSE_WAIT 
tcp        1      0 192.168.1.6:2049        192.168.1.4:720         CLOSE_WAIT 
tcp6       0      0 ::ffff:192.168.1.6:22   ::ffff:192.168.1.:38206 ESTABLISHED
tcp6       0      0 ::ffff:192.168.1.6:143  ::ffff:192.168.1.:41308 ESTABLISHED
tcp6       0      0 ::ffff:192.168.1.6:143  ::ffff:192.168.1.:55784 ESTABLISHED
tcp6       0      0 ::ffff:192.168.1.6:22   ::ffff:192.168.1.:39046 ESTABLISHED

and on the client

# netstat -t -n
Active Internet connections (w/o servers)
Proto Recv-Q Send-Q Local Address           Foreign Address         State      
tcp        0      0 192.168.1.4:943         192.168.1.6:2049        FIN_WAIT2  
tcp        0      0 192.168.1.4:33959       192.168.1.4:6543        ESTABLISHED
tcp        0      0 192.168.1.4:6543        192.168.1.4:54157       ESTABLISHED
tcp        0      0 127.0.0.1:13666         127.0.0.1:33364         ESTABLISHED
tcp        0      0 192.168.1.4:22          192.168.1.5:54696       ESTABLISHED
tcp        0      0 192.168.1.4:22          192.168.1.5:47599       ESTABLISHED
tcp        0      0 192.168.1.4:54156       192.168.1.4:6543        ESTABLISHED
tcp        0      0 192.168.1.4:6543        192.168.1.4:33957       ESTABLISHED
tcp        0      0 192.168.1.4:33957       192.168.1.4:6543        ESTABLISHED
tcp        0      0 192.168.1.4:54157       192.168.1.4:6543        ESTABLISHED
tcp        0      0 192.168.1.4:6543        192.168.1.4:54156       ESTABLISHED
tcp        0      0 192.168.1.4:6543        192.168.1.4:33959       ESTABLISHED
tcp        0      0 127.0.0.1:47756         127.0.0.1:6545          ESTABLISHED
tcp        0      0 127.0.0.1:33364         127.0.0.1:13666         ESTABLISHED
tcp        0      0 127.0.0.1:6545          127.0.0.1:47756         ESTABLISHED

> 
> Ian.
-- 
Ian Campbell

Just once, I wish we would encounter an alien menace that wasn't
immune to bullets.
		-- The Brigadier, "Dr. Who"

[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 197 bytes --]

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Trond Myklebust]

Can you see if the following 3 patches help? They're against 2.6.28-rc6,
but afaics the problems are pretty much the same on 2.6.26.

Cheers
  Trond

Re: [PATCH 1/3] SUNRPC: Ensure the server closes sockets in a timely fashion

[Trond Myklebust]

We want to ensure that connected sockets close down the connection when we
set XPT_CLOSE, so that we don't keep it hanging while cleaning up all the
stuff that is keeping a reference to the socket.

Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com>
---

 net/sunrpc/svcsock.c |   21 ++++++++++++++++++++-
 1 files changed, 20 insertions(+), 1 deletions(-)


diff --git a/net/sunrpc/svcsock.c b/net/sunrpc/svcsock.c
index 95293f5..a1b048d 100644
--- a/net/sunrpc/svcsock.c
+++ b/net/sunrpc/svcsock.c
@@ -59,6 +59,7 @@ static void		svc_udp_data_ready(struct sock *, int);
 static int		svc_udp_recvfrom(struct svc_rqst *);
 static int		svc_udp_sendto(struct svc_rqst *);
 static void		svc_sock_detach(struct svc_xprt *);
+static void		svc_tcp_sock_detach(struct svc_xprt *);
 static void		svc_sock_free(struct svc_xprt *);
 
 static struct svc_xprt *svc_create_socket(struct svc_serv *, int,
@@ -1017,7 +1018,7 @@ static struct svc_xprt_ops svc_tcp_ops = {
 	.xpo_recvfrom = svc_tcp_recvfrom,
 	.xpo_sendto = svc_tcp_sendto,
 	.xpo_release_rqst = svc_release_skb,
-	.xpo_detach = svc_sock_detach,
+	.xpo_detach = svc_tcp_sock_detach,
 	.xpo_free = svc_sock_free,
 	.xpo_prep_reply_hdr = svc_tcp_prep_reply_hdr,
 	.xpo_has_wspace = svc_tcp_has_wspace,
@@ -1282,6 +1283,24 @@ static void svc_sock_detach(struct svc_xprt *xprt)
 	sk->sk_state_change = svsk->sk_ostate;
 	sk->sk_data_ready = svsk->sk_odata;
 	sk->sk_write_space = svsk->sk_owspace;
+
+	if (sk->sk_sleep && waitqueue_active(sk->sk_sleep))
+		wake_up_interruptible(sk->sk_sleep);
+}
+
+/*
+ * Disconnect the socket, and reset the callbacks
+ */
+static void svc_tcp_sock_detach(struct svc_xprt *xprt)
+{
+	struct svc_sock *svsk = container_of(xprt, struct svc_sock, sk_xprt);
+
+	dprintk("svc: svc_tcp_sock_detach(%p)\n", svsk);
+
+	svc_sock_detach(xprt);
+
+	if (!test_bit(XPT_LISTENER, &xprt->xpt_flags))
+		kernel_sock_shutdown(svsk->sk_sock, SHUT_RDWR);
 }
 
 /*

-- 
Trond Myklebust
Linux NFS client maintainer

NetApp
Trond.Myklebust@netapp.com
www.netapp.com

Re: [PATCH 1/3] SUNRPC: Ensure the server closes sockets in a timely fashion

[Tom Tucker]

Trond Myklebust wrote:
> We want to ensure that connected sockets close down the connection when we
> set XPT_CLOSE, so that we don't keep it hanging while cleaning up all the
> stuff that is keeping a reference to the socket.
> 
> Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com>
> ---
> 
>  net/sunrpc/svcsock.c |   21 ++++++++++++++++++++-
>  1 files changed, 20 insertions(+), 1 deletions(-)
> 
> 
> diff --git a/net/sunrpc/svcsock.c b/net/sunrpc/svcsock.c
> index 95293f5..a1b048d 100644
> --- a/net/sunrpc/svcsock.c
> +++ b/net/sunrpc/svcsock.c
> @@ -59,6 +59,7 @@ static void		svc_udp_data_ready(struct sock *, int);
>  static int		svc_udp_recvfrom(struct svc_rqst *);
>  static int		svc_udp_sendto(struct svc_rqst *);
>  static void		svc_sock_detach(struct svc_xprt *);
> +static void		svc_tcp_sock_detach(struct svc_xprt *);
>  static void		svc_sock_free(struct svc_xprt *);
>  
>  static struct svc_xprt *svc_create_socket(struct svc_serv *, int,
> @@ -1017,7 +1018,7 @@ static struct svc_xprt_ops svc_tcp_ops = {
>  	.xpo_recvfrom = svc_tcp_recvfrom,
>  	.xpo_sendto = svc_tcp_sendto,
>  	.xpo_release_rqst = svc_release_skb,
> -	.xpo_detach = svc_sock_detach,
> +	.xpo_detach = svc_tcp_sock_detach,
>  	.xpo_free = svc_sock_free,
>  	.xpo_prep_reply_hdr = svc_tcp_prep_reply_hdr,
>  	.xpo_has_wspace = svc_tcp_has_wspace,
> @@ -1282,6 +1283,24 @@ static void svc_sock_detach(struct svc_xprt *xprt)
>  	sk->sk_state_change = svsk->sk_ostate;
>  	sk->sk_data_ready = svsk->sk_odata;
>  	sk->sk_write_space = svsk->sk_owspace;
> +
> +	if (sk->sk_sleep && waitqueue_active(sk->sk_sleep))
> +		wake_up_interruptible(sk->sk_sleep);
> +}
> +
> +/*
> + * Disconnect the socket, and reset the callbacks
> + */
> +static void svc_tcp_sock_detach(struct svc_xprt *xprt)
> +{
> +	struct svc_sock *svsk = container_of(xprt, struct svc_sock, sk_xprt);
> +
> +	dprintk("svc: svc_tcp_sock_detach(%p)\n", svsk);
> +
> +	svc_sock_detach(xprt);
> +
> +	if (!test_bit(XPT_LISTENER, &xprt->xpt_flags))
> +		kernel_sock_shutdown(svsk->sk_sock, SHUT_RDWR);

How is this different than what happens as an artifact of sock_release?

>  }
>  
>  /*
> 

Re: [PATCH 1/3] SUNRPC: Ensure the server closes sockets in a timely fashion

[Trond Myklebust]

On Wed, 2008-12-17 at 09:27 -0600, Tom Tucker wrote:
> > +	if (!test_bit(XPT_LISTENER, &xprt->xpt_flags))
> > +		kernel_sock_shutdown(svsk->sk_sock, SHUT_RDWR);
> 
> How is this different than what happens as an artifact of sock_release?

The point is that it is independent of whether or not something is
holding a reference to the svc_sock.

-- 
Trond Myklebust
Linux NFS client maintainer

NetApp
Trond.Myklebust@netapp.com
www.netapp.com

Re: [PATCH 1/3] SUNRPC: Ensure the server closes sockets in a timely fashion

[Tom Tucker]

Trond Myklebust wrote:
> On Wed, 2008-12-17 at 09:27 -0600, Tom Tucker wrote:
>>> +	if (!test_bit(XPT_LISTENER, &xprt->xpt_flags))
>>> +		kernel_sock_shutdown(svsk->sk_sock, SHUT_RDWR);
>> How is this different than what happens as an artifact of sock_release?
> 
> The point is that it is independent of whether or not something is
> holding a reference to the svc_sock.

Thanks, makes sense.

> 

Re: [PATCH 3/3] SUNRPC: svc_xprt_enqueue should not refuse to enqueue 'XPT_DEAD' transports

[Trond Myklebust]

Aside from being racy (there is nothing preventing someone setting XPT_DEAD
after the test in svc_xprt_enqueue, and before XPT_BUSY is set), it is
wrong to assume that transports which have called svc_delete_xprt() might
not need to be re-enqueued.

See the list of deferred requests, which is currently never going to
be cleared if the revisit call happens after svc_delete_xprt(). In this
case, the deferred request will currently keep a reference to the transport
forever.

The fix should be to allow dead transports to be enqueued in order to clear
the deferred requests, then change the order of processing in svc_recv() so
that we pick up deferred requests before we do the XPT_CLOSE processing.

Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com>
---

 net/sunrpc/svc_xprt.c |  124 +++++++++++++++++++++++++++----------------------
 1 files changed, 69 insertions(+), 55 deletions(-)


diff --git a/net/sunrpc/svc_xprt.c b/net/sunrpc/svc_xprt.c
index a417064..b54cf84 100644
--- a/net/sunrpc/svc_xprt.c
+++ b/net/sunrpc/svc_xprt.c
@@ -297,10 +297,15 @@ void svc_xprt_enqueue(struct svc_xprt *xprt)
 	struct svc_serv	*serv = xprt->xpt_server;
 	struct svc_pool *pool;
 	struct svc_rqst	*rqstp;
+	unsigned long flags;
 	int cpu;
 
-	if (!(xprt->xpt_flags &
-	      ((1<<XPT_CONN)|(1<<XPT_DATA)|(1<<XPT_CLOSE)|(1<<XPT_DEFERRED))))
+	flags = xprt->xpt_flags &
+		(1UL<<XPT_CONN | 1UL<<XPT_DATA | 1UL<<XPT_CLOSE |
+		 1UL<<XPT_DEAD | 1UL<<XPT_DEFERRED);
+	if (flags == 0)
+		return;
+	if ((flags & 1UL<<XPT_DEAD) != 0 && (flags & 1UL<<XPT_DEFERRED) == 0)
 		return;
 
 	cpu = get_cpu();
@@ -315,12 +320,6 @@ void svc_xprt_enqueue(struct svc_xprt *xprt)
 		       "svc_xprt_enqueue: "
 		       "threads and transports both waiting??\n");
 
-	if (test_bit(XPT_DEAD, &xprt->xpt_flags)) {
-		/* Don't enqueue dead transports */
-		dprintk("svc: transport %p is dead, not enqueued\n", xprt);
-		goto out_unlock;
-	}
-
 	/* Mark transport as busy. It will remain in this state until
 	 * the provider calls svc_xprt_received. We update XPT_BUSY
 	 * atomically because it also guards against trying to enqueue
@@ -566,6 +565,7 @@ static void svc_check_conn_limits(struct svc_serv *serv)
 int svc_recv(struct svc_rqst *rqstp, long timeout)
 {
 	struct svc_xprt		*xprt = NULL;
+	struct svc_xprt		*newxpt;
 	struct svc_serv		*serv = rqstp->rq_server;
 	struct svc_pool		*pool = rqstp->rq_pool;
 	int			len, i;
@@ -673,62 +673,76 @@ int svc_recv(struct svc_rqst *rqstp, long timeout)
 	spin_unlock_bh(&pool->sp_lock);
 
 	len = 0;
+
+	/*
+	 * Deal with deferred requests first, since they need to be
+	 * dequeued and dropped if the transport has been closed.
+	 */
+	rqstp->rq_deferred = svc_deferred_dequeue(xprt);
+	if (rqstp->rq_deferred) {
+		svc_xprt_received(xprt);
+		len = svc_deferred_recv(rqstp);
+	}
+
 	if (test_bit(XPT_CLOSE, &xprt->xpt_flags)) {
 		dprintk("svc_recv: found XPT_CLOSE\n");
 		svc_delete_xprt(xprt);
-	} else if (test_bit(XPT_LISTENER, &xprt->xpt_flags)) {
-		struct svc_xprt *newxpt;
-		newxpt = xprt->xpt_ops->xpo_accept(xprt);
-		if (newxpt) {
-			/*
-			 * We know this module_get will succeed because the
-			 * listener holds a reference too
-			 */
-			__module_get(newxpt->xpt_class->xcl_owner);
-			svc_check_conn_limits(xprt->xpt_server);
-			spin_lock_bh(&serv->sv_lock);
-			set_bit(XPT_TEMP, &newxpt->xpt_flags);
-			list_add(&newxpt->xpt_list, &serv->sv_tempsocks);
-			serv->sv_tmpcnt++;
-			if (serv->sv_temptimer.function == NULL) {
-				/* setup timer to age temp transports */
-				setup_timer(&serv->sv_temptimer,
-					    svc_age_temp_xprts,
-					    (unsigned long)serv);
-				mod_timer(&serv->sv_temptimer,
-					  jiffies + svc_conn_age_period * HZ);
-			}
-			spin_unlock_bh(&serv->sv_lock);
-			svc_xprt_received(newxpt);
-		}
-		svc_xprt_received(xprt);
-	} else {
-		dprintk("svc: server %p, pool %u, transport %p, inuse=%d\n",
-			rqstp, pool->sp_id, xprt,
-			atomic_read(&xprt->xpt_ref.refcount));
-		rqstp->rq_deferred = svc_deferred_dequeue(xprt);
-		if (rqstp->rq_deferred) {
-			svc_xprt_received(xprt);
-			len = svc_deferred_recv(rqstp);
-		} else
+		goto drop_request;
+	}
+
+	if (!test_bit(XPT_LISTENER, &xprt->xpt_flags)) {
+		if (len == 0) {
+			dprintk("svc: server %p, pool %u, transport %p, inuse=%d\n",
+					rqstp, pool->sp_id, xprt,
+					atomic_read(&xprt->xpt_ref.refcount));
 			len = xprt->xpt_ops->xpo_recvfrom(rqstp);
+
+			/* No data, incomplete (TCP) read, or accept() */
+			if (len == 0 || len == -EAGAIN)
+				goto drop_request;
+		}
+
 		dprintk("svc: got len=%d\n", len);
-	}
 
-	/* No data, incomplete (TCP) read, or accept() */
-	if (len == 0 || len == -EAGAIN) {
-		rqstp->rq_res.len = 0;
-		svc_xprt_release(rqstp);
-		return -EAGAIN;
+		clear_bit(XPT_OLD, &xprt->xpt_flags);
+
+		rqstp->rq_secure = svc_port_is_privileged(svc_addr(rqstp));
+		rqstp->rq_chandle.defer = svc_defer;
+
+		if (serv->sv_stats)
+			serv->sv_stats->netcnt++;
+		return len;
 	}
-	clear_bit(XPT_OLD, &xprt->xpt_flags);
 
-	rqstp->rq_secure = svc_port_is_privileged(svc_addr(rqstp));
-	rqstp->rq_chandle.defer = svc_defer;
+	newxpt = xprt->xpt_ops->xpo_accept(xprt);
+	if (newxpt) {
+		/*
+		 * We know this module_get will succeed because the
+		 * listener holds a reference too
+		 */
+		__module_get(newxpt->xpt_class->xcl_owner);
+		svc_check_conn_limits(xprt->xpt_server);
+		spin_lock_bh(&serv->sv_lock);
+		set_bit(XPT_TEMP, &newxpt->xpt_flags);
+		list_add(&newxpt->xpt_list, &serv->sv_tempsocks);
+		serv->sv_tmpcnt++;
+		if (serv->sv_temptimer.function == NULL) {
+			/* setup timer to age temp transports */
+			setup_timer(&serv->sv_temptimer,
+				    svc_age_temp_xprts,
+				    (unsigned long)serv);
+			mod_timer(&serv->sv_temptimer,
+				  jiffies + svc_conn_age_period * HZ);
+		}
+		spin_unlock_bh(&serv->sv_lock);
+		svc_xprt_received(newxpt);
+	}
+	svc_xprt_received(xprt);
 
-	if (serv->sv_stats)
-		serv->sv_stats->netcnt++;
-	return len;
+drop_request:
+	rqstp->rq_res.len = 0;
+	svc_xprt_release(rqstp);
+	return -EAGAIN;
 }
 EXPORT_SYMBOL(svc_recv);
 

-- 
Trond Myklebust
Linux NFS client maintainer

NetApp
Trond.Myklebust@netapp.com
www.netapp.com

Re: [PATCH 3/3] SUNRPC: svc_xprt_enqueue should not refuse to enqueue 'XPT_DEAD' transports

[Tom Tucker]

Trond Myklebust wrote:
> Aside from being racy (there is nothing preventing someone setting XPT_DEAD
> after the test in svc_xprt_enqueue, and before XPT_BUSY is set), it is
> wrong to assume that transports which have called svc_delete_xprt() might
> not need to be re-enqueued.

This is only true because now you allow transports with XPT_DEAD set to 
be enqueued -- yes?

> 
> See the list of deferred requests, which is currently never going to
> be cleared if the revisit call happens after svc_delete_xprt(). In this
> case, the deferred request will currently keep a reference to the transport
> forever.
>

I agree this is a possibility and it needs to be fixed. I'm concerned 
that the root cause is still there though. I thought the test case was 
the client side timing out the connection. Why are there deferred 
requests sitting on what is presumably an idle connection?


> The fix should be to allow dead transports to be enqueued in order to clear
> the deferred requests, then change the order of processing in svc_recv() so
> that we pick up deferred requests before we do the XPT_CLOSE processing.
> 

Wouldn't it be simpler to clean up any deferred requests in the close 
path instead of changing the meaning of XPT_DEAD and dispatching 
N-threads to do the same?

> Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com>
> ---
> 
>  net/sunrpc/svc_xprt.c |  124 +++++++++++++++++++++++++++----------------------
>  1 files changed, 69 insertions(+), 55 deletions(-)
> 
> 
> diff --git a/net/sunrpc/svc_xprt.c b/net/sunrpc/svc_xprt.c
> index a417064..b54cf84 100644
> --- a/net/sunrpc/svc_xprt.c
> +++ b/net/sunrpc/svc_xprt.c
> @@ -297,10 +297,15 @@ void svc_xprt_enqueue(struct svc_xprt *xprt)
>  	struct svc_serv	*serv = xprt->xpt_server;
>  	struct svc_pool *pool;
>  	struct svc_rqst	*rqstp;
> +	unsigned long flags;
>  	int cpu;
>  
> -	if (!(xprt->xpt_flags &
> -	      ((1<<XPT_CONN)|(1<<XPT_DATA)|(1<<XPT_CLOSE)|(1<<XPT_DEFERRED))))
> +	flags = xprt->xpt_flags &
> +		(1UL<<XPT_CONN | 1UL<<XPT_DATA | 1UL<<XPT_CLOSE |
> +		 1UL<<XPT_DEAD | 1UL<<XPT_DEFERRED);
> +	if (flags == 0)
> +		return;
> +	if ((flags & 1UL<<XPT_DEAD) != 0 && (flags & 1UL<<XPT_DEFERRED) == 0)
>  		return;
>  
>  	cpu = get_cpu();
> @@ -315,12 +320,6 @@ void svc_xprt_enqueue(struct svc_xprt *xprt)
>  		       "svc_xprt_enqueue: "
>  		       "threads and transports both waiting??\n");
>  
> -	if (test_bit(XPT_DEAD, &xprt->xpt_flags)) {
> -		/* Don't enqueue dead transports */
> -		dprintk("svc: transport %p is dead, not enqueued\n", xprt);
> -		goto out_unlock;
> -	}
> -
>  	/* Mark transport as busy. It will remain in this state until
>  	 * the provider calls svc_xprt_received. We update XPT_BUSY
>  	 * atomically because it also guards against trying to enqueue
> @@ -566,6 +565,7 @@ static void svc_check_conn_limits(struct svc_serv *serv)
>  int svc_recv(struct svc_rqst *rqstp, long timeout)
>  {
>  	struct svc_xprt		*xprt = NULL;
> +	struct svc_xprt		*newxpt;
>  	struct svc_serv		*serv = rqstp->rq_server;
>  	struct svc_pool		*pool = rqstp->rq_pool;
>  	int			len, i;
> @@ -673,62 +673,76 @@ int svc_recv(struct svc_rqst *rqstp, long timeout)
>  	spin_unlock_bh(&pool->sp_lock);
>  
>  	len = 0;
> +
> +	/*
> +	 * Deal with deferred requests first, since they need to be
> +	 * dequeued and dropped if the transport has been closed.
> +	 */
> +	rqstp->rq_deferred = svc_deferred_dequeue(xprt);
> +	if (rqstp->rq_deferred) {
> +		svc_xprt_received(xprt);
> +		len = svc_deferred_recv(rqstp);
> +	}
> +
>  	if (test_bit(XPT_CLOSE, &xprt->xpt_flags)) {
>  		dprintk("svc_recv: found XPT_CLOSE\n");
>  		svc_delete_xprt(xprt);
> -	} else if (test_bit(XPT_LISTENER, &xprt->xpt_flags)) {
> -		struct svc_xprt *newxpt;
> -		newxpt = xprt->xpt_ops->xpo_accept(xprt);
> -		if (newxpt) {
> -			/*
> -			 * We know this module_get will succeed because the
> -			 * listener holds a reference too
> -			 */
> -			__module_get(newxpt->xpt_class->xcl_owner);
> -			svc_check_conn_limits(xprt->xpt_server);
> -			spin_lock_bh(&serv->sv_lock);
> -			set_bit(XPT_TEMP, &newxpt->xpt_flags);
> -			list_add(&newxpt->xpt_list, &serv->sv_tempsocks);
> -			serv->sv_tmpcnt++;
> -			if (serv->sv_temptimer.function == NULL) {
> -				/* setup timer to age temp transports */
> -				setup_timer(&serv->sv_temptimer,
> -					    svc_age_temp_xprts,
> -					    (unsigned long)serv);
> -				mod_timer(&serv->sv_temptimer,
> -					  jiffies + svc_conn_age_period * HZ);
> -			}
> -			spin_unlock_bh(&serv->sv_lock);
> -			svc_xprt_received(newxpt);
> -		}
> -		svc_xprt_received(xprt);
> -	} else {
> -		dprintk("svc: server %p, pool %u, transport %p, inuse=%d\n",
> -			rqstp, pool->sp_id, xprt,
> -			atomic_read(&xprt->xpt_ref.refcount));
> -		rqstp->rq_deferred = svc_deferred_dequeue(xprt);
> -		if (rqstp->rq_deferred) {
> -			svc_xprt_received(xprt);
> -			len = svc_deferred_recv(rqstp);
> -		} else
> +		goto drop_request;
> +	}
> +
> +	if (!test_bit(XPT_LISTENER, &xprt->xpt_flags)) {
> +		if (len == 0) {
> +			dprintk("svc: server %p, pool %u, transport %p, inuse=%d\n",
> +					rqstp, pool->sp_id, xprt,
> +					atomic_read(&xprt->xpt_ref.refcount));
>  			len = xprt->xpt_ops->xpo_recvfrom(rqstp);
> +
> +			/* No data, incomplete (TCP) read, or accept() */
> +			if (len == 0 || len == -EAGAIN)
> +				goto drop_request;
> +		}
> +
>  		dprintk("svc: got len=%d\n", len);
> -	}
>  
> -	/* No data, incomplete (TCP) read, or accept() */
> -	if (len == 0 || len == -EAGAIN) {
> -		rqstp->rq_res.len = 0;
> -		svc_xprt_release(rqstp);
> -		return -EAGAIN;
> +		clear_bit(XPT_OLD, &xprt->xpt_flags);
> +
> +		rqstp->rq_secure = svc_port_is_privileged(svc_addr(rqstp));
> +		rqstp->rq_chandle.defer = svc_defer;
> +
> +		if (serv->sv_stats)
> +			serv->sv_stats->netcnt++;
> +		return len;
>  	}
> -	clear_bit(XPT_OLD, &xprt->xpt_flags);
>  
> -	rqstp->rq_secure = svc_port_is_privileged(svc_addr(rqstp));
> -	rqstp->rq_chandle.defer = svc_defer;
> +	newxpt = xprt->xpt_ops->xpo_accept(xprt);
> +	if (newxpt) {
> +		/*
> +		 * We know this module_get will succeed because the
> +		 * listener holds a reference too
> +		 */
> +		__module_get(newxpt->xpt_class->xcl_owner);
> +		svc_check_conn_limits(xprt->xpt_server);
> +		spin_lock_bh(&serv->sv_lock);
> +		set_bit(XPT_TEMP, &newxpt->xpt_flags);
> +		list_add(&newxpt->xpt_list, &serv->sv_tempsocks);
> +		serv->sv_tmpcnt++;
> +		if (serv->sv_temptimer.function == NULL) {
> +			/* setup timer to age temp transports */
> +			setup_timer(&serv->sv_temptimer,
> +				    svc_age_temp_xprts,
> +				    (unsigned long)serv);
> +			mod_timer(&serv->sv_temptimer,
> +				  jiffies + svc_conn_age_period * HZ);
> +		}
> +		spin_unlock_bh(&serv->sv_lock);
> +		svc_xprt_received(newxpt);
> +	}
> +	svc_xprt_received(xprt);
>  
> -	if (serv->sv_stats)
> -		serv->sv_stats->netcnt++;
> -	return len;
> +drop_request:
> +	rqstp->rq_res.len = 0;
> +	svc_xprt_release(rqstp);
> +	return -EAGAIN;
>  }
>  EXPORT_SYMBOL(svc_recv);
>  
> 

Re: [PATCH 3/3] SUNRPC: svc_xprt_enqueue should not refuse to enqueue 'XPT_DEAD' transports

[Trond Myklebust]

On Wed, 2008-12-17 at 09:35 -0600, Tom Tucker wrote:
> Trond Myklebust wrote:
> > Aside from being racy (there is nothing preventing someone setting XPT_DEAD
> > after the test in svc_xprt_enqueue, and before XPT_BUSY is set), it is
> > wrong to assume that transports which have called svc_delete_xprt() might
> > not need to be re-enqueued.
> 
> This is only true because now you allow transports with XPT_DEAD set to 
> be enqueued -- yes?
> 
> > 
> > See the list of deferred requests, which is currently never going to
> > be cleared if the revisit call happens after svc_delete_xprt(). In this
> > case, the deferred request will currently keep a reference to the transport
> > forever.
> >
> 
> I agree this is a possibility and it needs to be fixed. I'm concerned 
> that the root cause is still there though. I thought the test case was 
> the client side timing out the connection. Why are there deferred 
> requests sitting on what is presumably an idle connection?

I haven't said that they are the cause of this test case. I've said that
deferred requests hold references to the socket that can obviously
deadlock. That needs to be fixed regardless of whether or not it is the
cause here.

There are plenty of situations in which the client may choose to close
the TCP socket even if there are outstanding requests. One of the most
common is when the user signals the process, so that an RPC call that
was partially transmitted (ran out of buffer space) gets cancelled
before it can finish transmitting. In that case the client has no choice
but to disconnect and immediately reconnect.

> > The fix should be to allow dead transports to be enqueued in order to clear
> > the deferred requests, then change the order of processing in svc_recv() so
> > that we pick up deferred requests before we do the XPT_CLOSE processing.
> > 
> 
> Wouldn't it be simpler to clean up any deferred requests in the close 
> path instead of changing the meaning of XPT_DEAD and dispatching 
> N-threads to do the same?

AFAICS, deferred requests are the property of the cache until they
expire or a downcall occurs. I'm not aware of any way to cancel only
those deferred requests that hold a reference to this particular
transport.

-- 
Trond Myklebust
Linux NFS client maintainer

NetApp
Trond.Myklebust@netapp.com
www.netapp.com

Re: [PATCH 3/3] SUNRPC: svc_xprt_enqueue should not refuse to enqueue 'XPT_DEAD' transports

[Tom Tucker]

Trond Myklebust wrote:
> On Wed, 2008-12-17 at 09:35 -0600, Tom Tucker wrote:
>   
>> Trond Myklebust wrote:
>>     
>>> Aside from being racy (there is nothing preventing someone setting XPT_DEAD
>>> after the test in svc_xprt_enqueue, and before XPT_BUSY is set), it is
>>> wrong to assume that transports which have called svc_delete_xprt() might
>>> not need to be re-enqueued.
>>>       
>> This is only true because now you allow transports with XPT_DEAD set to 
>> be enqueued -- yes?
>>
>>     
>>> See the list of deferred requests, which is currently never going to
>>> be cleared if the revisit call happens after svc_delete_xprt(). In this
>>> case, the deferred request will currently keep a reference to the transport
>>> forever.
>>>
>>>       
>> I agree this is a possibility and it needs to be fixed. I'm concerned 
>> that the root cause is still there though. I thought the test case was 
>> the client side timing out the connection. Why are there deferred 
>> requests sitting on what is presumably an idle connection?
>>     
>
> I haven't said that they are the cause of this test case. I've said that
> deferred requests hold references to the socket that can obviously
> deadlock. That needs to be fixed regardless of whether or not it is the
> cause here.
>
> There are plenty of situations in which the client may choose to close
> the TCP socket even if there are outstanding requests. One of the most
> common is when the user signals the process, so that an RPC call that
> was partially transmitted (ran out of buffer space) gets cancelled
> before it can finish transmitting. In that case the client has no choice
> but to disconnect and immediately reconnect.
>
>   
>>> The fix should be to allow dead transports to be enqueued in order to clear
>>> the deferred requests, then change the order of processing in svc_recv() so
>>> that we pick up deferred requests before we do the XPT_CLOSE processing.
>>>
>>>       
>> Wouldn't it be simpler to clean up any deferred requests in the close 
>> path instead of changing the meaning of XPT_DEAD and dispatching 
>> N-threads to do the same?
>>     
>
> AFAICS, deferred requests are the property of the cache until they
> expire or a downcall occurs. I'm not aware of any way to cancel only
> those deferred requests that hold a reference to this particular
> transport.
>
>   
Ok, I think you're right, and I think that this fix is correct and makes 
the symptom go away.

I may be completely confused here, but:

- The deferred requests should be getting cleaned up by timing out, and 
that does not not seem to be happening, (Is this true?)

- By releasing the underlying connection prior to releasing the 
transport that manages it, we've converted the visible resource leek to 
an invisible one.

- This has been around forever and changing the client side close 
behavior graceful exposed this bug,

So I'm wondering if what we want to do here is to provide a mechanism 
for canceling deferred requests for a particular transport. This would 
provide a mechanism for the generic transport driver to force 
cancellation of deferred requests when closing.

Tom

Re: [PATCH 3/3] SUNRPC: svc_xprt_enqueue should not refuse to enqueue 'XPT_DEAD' transports

[Tom Tucker]

Tom Tucker wrote:
> Trond Myklebust wrote:
>> On Wed, 2008-12-17 at 09:35 -0600, Tom Tucker wrote:
>>  
>>> Trond Myklebust wrote:
>>>    
>>>> Aside from being racy (there is nothing preventing someone setting 
>>>> XPT_DEAD
>>>> after the test in svc_xprt_enqueue, and before XPT_BUSY is set), it is
>>>> wrong to assume that transports which have called svc_delete_xprt() 
>>>> might
>>>> not need to be re-enqueued.
>>>>       
>>> This is only true because now you allow transports with XPT_DEAD set 
>>> to be enqueued -- yes?
>>>
>>>    
>>>> See the list of deferred requests, which is currently never going to
>>>> be cleared if the revisit call happens after svc_delete_xprt(). In 
>>>> this
>>>> case, the deferred request will currently keep a reference to the 
>>>> transport
>>>> forever.
>>>>
>>>>       
>>> I agree this is a possibility and it needs to be fixed. I'm 
>>> concerned that the root cause is still there though. I thought the 
>>> test case was the client side timing out the connection. Why are 
>>> there deferred requests sitting on what is presumably an idle 
>>> connection?
>>>     
>>
>> I haven't said that they are the cause of this test case. I've said that
>> deferred requests hold references to the socket that can obviously
>> deadlock. That needs to be fixed regardless of whether or not it is the
>> cause here.
>>
>> There are plenty of situations in which the client may choose to close
>> the TCP socket even if there are outstanding requests. One of the most
>> common is when the user signals the process, so that an RPC call that
>> was partially transmitted (ran out of buffer space) gets cancelled
>> before it can finish transmitting. In that case the client has no choice
>> but to disconnect and immediately reconnect.
>>
>>  
>>>> The fix should be to allow dead transports to be enqueued in order 
>>>> to clear
>>>> the deferred requests, then change the order of processing in 
>>>> svc_recv() so
>>>> that we pick up deferred requests before we do the XPT_CLOSE 
>>>> processing.
>>>>
>>>>       
>>> Wouldn't it be simpler to clean up any deferred requests in the 
>>> close path instead of changing the meaning of XPT_DEAD and 
>>> dispatching N-threads to do the same?
>>>     
>>
>> AFAICS, deferred requests are the property of the cache until they
>> expire or a downcall occurs. I'm not aware of any way to cancel only
>> those deferred requests that hold a reference to this particular
>> transport.
>>
>>   
> Ok, I think you're right, and I think that this fix is correct and 
> makes the symptom go away.
>
> I may be completely confused here, but:
>
> - The deferred requests should be getting cleaned up by timing out, 
> and that does not not seem to be happening, (Is this true?)
>
They are getting "cleaned up", but by the time they do the transport is 
dead, the request has been added to the deferred queue, but it won't get 
processed because svc_xprt_enqueue won't "schedule" a dead transport.

> - By releasing the underlying connection prior to releasing the 
> transport that manages it, we've converted the visible resource leek 
> to an invisible one.
>
Not with your changes per the above.

> - This has been around forever and changing the client side close 
> behavior graceful exposed this bug,
>
> So I'm wondering if what we want to do here is to provide a mechanism 
> for canceling deferred requests for a particular transport. This would 
> provide a mechanism for the generic transport driver to force 
> cancellation of deferred requests when closing. 
This is a new interface and we'd still need to handle requests sitting 
on the transport's deferred queue. Probably not a good idea.

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

Re: [PATCH 3/3] SUNRPC: svc_xprt_enqueue should not refuse to enqueue 'XPT_DEAD' transports

[Tom Tucker]

Bruce/Trond:

This is an alternative to patches 2 and 3 from Trond's fix. I think 
Trond's fix is correct, but I believe this approach to be simpler.

From: Tom Tucker <tom@opengridcomputing.com>
Date: Wed, 31 Dec 2008 17:18:33 -0600
Subject: [PATCH] svc: Clean up deferred requests on transport destruction

A race between svc_revisit and svc_delete_xprt can result in
deferred requests holding references on a transport that can never be
recovered because dead transports are not enqueued for subsequent
processing.

Check for XPT_DEAD in revisit to clean up completing deferrals on a dead
transport and sweep a transport's deferred queue to do the same for queued
but unprocessed deferrals.

Signed-off-by: Tom Tucker <tom@opengridcomputing.com>
---
 net/sunrpc/svc_xprt.c |   20 +++++++++++++++-----
 1 files changed, 15 insertions(+), 5 deletions(-)

diff --git a/net/sunrpc/svc_xprt.c b/net/sunrpc/svc_xprt.c
index bf5b5cd..92ca5c6 100644
--- a/net/sunrpc/svc_xprt.c
+++ b/net/sunrpc/svc_xprt.c
@@ -837,6 +837,11 @@ static void svc_age_temp_xprts(unsigned long closure)
 void svc_delete_xprt(struct svc_xprt *xprt)
 {
        struct svc_serv *serv = xprt->xpt_server;
+       struct svc_deferred_req *dr;
+
+       /* Only do this once */
+       if (test_and_set_bit(XPT_DEAD, &xprt->xpt_flags))
+               return;

        dprintk("svc: svc_delete_xprt(%p)\n", xprt);
        xprt->xpt_ops->xpo_detach(xprt);
@@ -851,12 +856,16 @@ void svc_delete_xprt(struct svc_xprt *xprt)
         * while still attached to a queue, the queue itself
         * is about to be destroyed (in svc_destroy).
         */
-       if (!test_and_set_bit(XPT_DEAD, &xprt->xpt_flags)) {
-               BUG_ON(atomic_read(&xprt->xpt_ref.refcount) < 2);
-               if (test_bit(XPT_TEMP, &xprt->xpt_flags))
-                       serv->sv_tmpcnt--;
+       if (test_bit(XPT_TEMP, &xprt->xpt_flags))
+               serv->sv_tmpcnt--;
+
+       for (dr = svc_deferred_dequeue(xprt); dr;
+            dr = svc_deferred_dequeue(xprt)) {
                svc_xprt_put(xprt);
+               kfree(dr);
        }
+
+       svc_xprt_put(xprt);
        spin_unlock_bh(&serv->sv_lock);
 }

@@ -902,7 +911,8 @@ static void svc_revisit(struct cache_deferred_req *dreq, int too_many)
                container_of(dreq, struct svc_deferred_req, handle);
        struct svc_xprt *xprt = dr->xprt;

-       if (too_many) {
+       if (too_many || test_bit(XPT_DEAD, &xprt->xpt_flags)) {
+               dprintk("revisit cancelled\n");
                svc_xprt_put(xprt);
                kfree(dr);
                return;

Re: [PATCH 3/3] SUNRPC: svc_xprt_enqueue should not refuse to enqueue 'XPT_DEAD' transports

[Trond Myklebust]

On Fri, 2009-01-02 at 15:44 -0600, Tom Tucker wrote:
> Bruce/Trond:
> 
> This is an alternative to patches 2 and 3 from Trond's fix. I think 
> Trond's fix is correct, but I believe this approach to be simpler.
> 
> From: Tom Tucker <tom@opengridcomputing.com>
> Date: Wed, 31 Dec 2008 17:18:33 -0600
> Subject: [PATCH] svc: Clean up deferred requests on transport destruction
> 
> A race between svc_revisit and svc_delete_xprt can result in
> deferred requests holding references on a transport that can never be
> recovered because dead transports are not enqueued for subsequent
> processing.
> 
> Check for XPT_DEAD in revisit to clean up completing deferrals on a dead
> transport and sweep a transport's deferred queue to do the same for queued
> but unprocessed deferrals.
> 
> Signed-off-by: Tom Tucker <tom@opengridcomputing.com>
> ---
>  net/sunrpc/svc_xprt.c |   20 +++++++++++++++-----
>  1 files changed, 15 insertions(+), 5 deletions(-)
> 
> diff --git a/net/sunrpc/svc_xprt.c b/net/sunrpc/svc_xprt.c
> index bf5b5cd..92ca5c6 100644
> --- a/net/sunrpc/svc_xprt.c
> +++ b/net/sunrpc/svc_xprt.c
> @@ -837,6 +837,11 @@ static void svc_age_temp_xprts(unsigned long closure)
>  void svc_delete_xprt(struct svc_xprt *xprt)
>  {
>         struct svc_serv *serv = xprt->xpt_server;
> +       struct svc_deferred_req *dr;
> +
> +       /* Only do this once */
> +       if (test_and_set_bit(XPT_DEAD, &xprt->xpt_flags))
> +               return;
> 
>         dprintk("svc: svc_delete_xprt(%p)\n", xprt);
>         xprt->xpt_ops->xpo_detach(xprt);
> @@ -851,12 +856,16 @@ void svc_delete_xprt(struct svc_xprt *xprt)
>          * while still attached to a queue, the queue itself
>          * is about to be destroyed (in svc_destroy).
>          */
> -       if (!test_and_set_bit(XPT_DEAD, &xprt->xpt_flags)) {
> -               BUG_ON(atomic_read(&xprt->xpt_ref.refcount) < 2);
> -               if (test_bit(XPT_TEMP, &xprt->xpt_flags))
> -                       serv->sv_tmpcnt--;
> +       if (test_bit(XPT_TEMP, &xprt->xpt_flags))
> +               serv->sv_tmpcnt--;
> +
> +       for (dr = svc_deferred_dequeue(xprt); dr;
> +            dr = svc_deferred_dequeue(xprt)) {
>                 svc_xprt_put(xprt);
> +               kfree(dr);
>         }
> +
> +       svc_xprt_put(xprt);
>         spin_unlock_bh(&serv->sv_lock);
>  }
> 
> @@ -902,7 +911,8 @@ static void svc_revisit(struct cache_deferred_req *dreq, int too_many)
>                 container_of(dreq, struct svc_deferred_req, handle);
>         struct svc_xprt *xprt = dr->xprt;
> 
> -       if (too_many) {
> +       if (too_many || test_bit(XPT_DEAD, &xprt->xpt_flags)) {
> +               dprintk("revisit cancelled\n");
>                 svc_xprt_put(xprt);
>                 kfree(dr);
>                 return;
> 

I see nothing that stops svc_delete_xprt() from setting XPT_DEAD after
the above test in svc_revisit(), and before the test inside
svc_xprt_enqueue(). What's preventing a race there?

Trond
-- 
Trond Myklebust
Linux NFS client maintainer

NetApp
Trond.Myklebust@netapp.com
www.netapp.com

Re: [PATCH 3/3] SUNRPC: svc_xprt_enqueue should not refuse to enqueue 'XPT_DEAD' transports

[Trond Myklebust]

On Sun, 2009-01-04 at 14:12 -0500, Trond Myklebust wrote:
> On Fri, 2009-01-02 at 15:44 -0600, Tom Tucker wrote:
> > Bruce/Trond:
> > 
> > This is an alternative to patches 2 and 3 from Trond's fix. I think 
> > Trond's fix is correct, but I believe this approach to be simpler.
> > 
> > From: Tom Tucker <tom@opengridcomputing.com>
> > Date: Wed, 31 Dec 2008 17:18:33 -0600
> > Subject: [PATCH] svc: Clean up deferred requests on transport destruction
> > 
> > A race between svc_revisit and svc_delete_xprt can result in
> > deferred requests holding references on a transport that can never be
> > recovered because dead transports are not enqueued for subsequent
> > processing.
> > 
> > Check for XPT_DEAD in revisit to clean up completing deferrals on a dead
> > transport and sweep a transport's deferred queue to do the same for queued
> > but unprocessed deferrals.
> > 
> > Signed-off-by: Tom Tucker <tom@opengridcomputing.com>
> > ---
> >  net/sunrpc/svc_xprt.c |   20 +++++++++++++++-----
> >  1 files changed, 15 insertions(+), 5 deletions(-)
> > 
> > diff --git a/net/sunrpc/svc_xprt.c b/net/sunrpc/svc_xprt.c
> > index bf5b5cd..92ca5c6 100644
> > --- a/net/sunrpc/svc_xprt.c
> > +++ b/net/sunrpc/svc_xprt.c
> > @@ -837,6 +837,11 @@ static void svc_age_temp_xprts(unsigned long closure)
> >  void svc_delete_xprt(struct svc_xprt *xprt)
> >  {
> >         struct svc_serv *serv = xprt->xpt_server;
> > +       struct svc_deferred_req *dr;
> > +
> > +       /* Only do this once */
> > +       if (test_and_set_bit(XPT_DEAD, &xprt->xpt_flags))
> > +               return;
> > 
> >         dprintk("svc: svc_delete_xprt(%p)\n", xprt);
> >         xprt->xpt_ops->xpo_detach(xprt);
> > @@ -851,12 +856,16 @@ void svc_delete_xprt(struct svc_xprt *xprt)
> >          * while still attached to a queue, the queue itself
> >          * is about to be destroyed (in svc_destroy).
> >          */
> > -       if (!test_and_set_bit(XPT_DEAD, &xprt->xpt_flags)) {
> > -               BUG_ON(atomic_read(&xprt->xpt_ref.refcount) < 2);
> > -               if (test_bit(XPT_TEMP, &xprt->xpt_flags))
> > -                       serv->sv_tmpcnt--;
> > +       if (test_bit(XPT_TEMP, &xprt->xpt_flags))
> > +               serv->sv_tmpcnt--;
> > +
> > +       for (dr = svc_deferred_dequeue(xprt); dr;
> > +            dr = svc_deferred_dequeue(xprt)) {
> >                 svc_xprt_put(xprt);
> > +               kfree(dr);
> >         }
> > +
> > +       svc_xprt_put(xprt);
> >         spin_unlock_bh(&serv->sv_lock);
> >  }
> > 
> > @@ -902,7 +911,8 @@ static void svc_revisit(struct cache_deferred_req *dreq, int too_many)
> >                 container_of(dreq, struct svc_deferred_req, handle);
> >         struct svc_xprt *xprt = dr->xprt;
> > 
> > -       if (too_many) {
> > +       if (too_many || test_bit(XPT_DEAD, &xprt->xpt_flags)) {
> > +               dprintk("revisit cancelled\n");
> >                 svc_xprt_put(xprt);
> >                 kfree(dr);
> >                 return;
> > 
> 
> I see nothing that stops svc_delete_xprt() from setting XPT_DEAD after
> the above test in svc_revisit(), and before the test inside
> svc_xprt_enqueue(). What's preventing a race there?

I suppose one way to fix it would be to hold the xprt->xpt_lock across
the above test, and to make sure that you set XPT_DEFERRED while holding
the lock, and _before_ you test for XPT_DEAD. That way, you guarantee
that the svc_deferred_dequeue() loop in svc_delete_xprt() will pick up
anything that races with the setting of XPT_DEAD.

Trond

Re: [PATCH 3/3] SUNRPC: svc_xprt_enqueue should not refuse to enqueue 'XPT_DEAD' transports

[Tom Tucker]

Trond Myklebust wrote:
> On Fri, 2009-01-02 at 15:44 -0600, Tom Tucker wrote:
>> Bruce/Trond:
>>
>> This is an alternative to patches 2 and 3 from Trond's fix. I think 
>> Trond's fix is correct, but I believe this approach to be simpler.
>>
>> From: Tom Tucker <tom@opengridcomputing.com>
>> Date: Wed, 31 Dec 2008 17:18:33 -0600
>> Subject: [PATCH] svc: Clean up deferred requests on transport destruction
>>
>> A race between svc_revisit and svc_delete_xprt can result in
>> deferred requests holding references on a transport that can never be
>> recovered because dead transports are not enqueued for subsequent
>> processing.
>>
>> Check for XPT_DEAD in revisit to clean up completing deferrals on a dead
>> transport and sweep a transport's deferred queue to do the same for queued
>> but unprocessed deferrals.
>>
>> Signed-off-by: Tom Tucker <tom@opengridcomputing.com>
>> ---
>>  net/sunrpc/svc_xprt.c |   20 +++++++++++++++-----
>>  1 files changed, 15 insertions(+), 5 deletions(-)
>>
>> diff --git a/net/sunrpc/svc_xprt.c b/net/sunrpc/svc_xprt.c
>> index bf5b5cd..92ca5c6 100644
>> --- a/net/sunrpc/svc_xprt.c
>> +++ b/net/sunrpc/svc_xprt.c
>> @@ -837,6 +837,11 @@ static void svc_age_temp_xprts(unsigned long closure)
>>  void svc_delete_xprt(struct svc_xprt *xprt)
>>  {
>>         struct svc_serv *serv = xprt->xpt_server;
>> +       struct svc_deferred_req *dr;
>> +
>> +       /* Only do this once */
>> +       if (test_and_set_bit(XPT_DEAD, &xprt->xpt_flags))
>> +               return;
>>
>>         dprintk("svc: svc_delete_xprt(%p)\n", xprt);
>>         xprt->xpt_ops->xpo_detach(xprt);
>> @@ -851,12 +856,16 @@ void svc_delete_xprt(struct svc_xprt *xprt)
>>          * while still attached to a queue, the queue itself
>>          * is about to be destroyed (in svc_destroy).
>>          */
>> -       if (!test_and_set_bit(XPT_DEAD, &xprt->xpt_flags)) {
>> -               BUG_ON(atomic_read(&xprt->xpt_ref.refcount) < 2);
>> -               if (test_bit(XPT_TEMP, &xprt->xpt_flags))
>> -                       serv->sv_tmpcnt--;
>> +       if (test_bit(XPT_TEMP, &xprt->xpt_flags))
>> +               serv->sv_tmpcnt--;
>> +
>> +       for (dr = svc_deferred_dequeue(xprt); dr;
>> +            dr = svc_deferred_dequeue(xprt)) {
>>                 svc_xprt_put(xprt);
>> +               kfree(dr);
>>         }
>> +

If there are queued deferrals that are not processed, they will be 
cleaned up here and their references dropped.

>> +       svc_xprt_put(xprt);
>>         spin_unlock_bh(&serv->sv_lock);
>>  }
>>
>> @@ -902,7 +911,8 @@ static void svc_revisit(struct cache_deferred_req *dreq, int too_many)
>>                 container_of(dreq, struct svc_deferred_req, handle);
>>         struct svc_xprt *xprt = dr->xprt;
>>
>> -       if (too_many) {
>> +       if (too_many || test_bit(XPT_DEAD, &xprt->xpt_flags)) {

If there were references held by the cache, they will get cleaned up here.

>> +               dprintk("revisit cancelled\n");
>>                 svc_xprt_put(xprt);
>>                 kfree(dr);
>>                 return;
>>
> 
> I see nothing that stops svc_delete_xprt() from setting XPT_DEAD after
> the above test in svc_revisit(), and before the test inside
> svc_xprt_enqueue(). What's preventing a race there?

Yep. I originally had a lock around the check for XPT_DEAD and the 
deferred enqueue, but convinced myself (incorrectly) it wasn't 
necessary. Erf.

Thanks, I'll repost a fix...

> 
> Trond

Re: [PATCH 3/3] SUNRPC: svc_xprt_enqueue should not refuse to enqueue 'XPT_DEAD' transports

[Tom Tucker]

Trond Myklebust wrote:
> On Sun, 2009-01-04 at 14:12 -0500, Trond Myklebust wrote:
>> On Fri, 2009-01-02 at 15:44 -0600, Tom Tucker wrote:
>>> Bruce/Trond:
>>>
>>> This is an alternative to patches 2 and 3 from Trond's fix. I think 
>>> Trond's fix is correct, but I believe this approach to be simpler.
>>>
>>> From: Tom Tucker <tom@opengridcomputing.com>
>>> Date: Wed, 31 Dec 2008 17:18:33 -0600
>>> Subject: [PATCH] svc: Clean up deferred requests on transport destruction
>>>
>>> A race between svc_revisit and svc_delete_xprt can result in
>>> deferred requests holding references on a transport that can never be
>>> recovered because dead transports are not enqueued for subsequent
>>> processing.
>>>
>>> Check for XPT_DEAD in revisit to clean up completing deferrals on a dead
>>> transport and sweep a transport's deferred queue to do the same for queued
>>> but unprocessed deferrals.
>>>
>>> Signed-off-by: Tom Tucker <tom@opengridcomputing.com>
>>> ---
>>>  net/sunrpc/svc_xprt.c |   20 +++++++++++++++-----
>>>  1 files changed, 15 insertions(+), 5 deletions(-)
>>>
>>> diff --git a/net/sunrpc/svc_xprt.c b/net/sunrpc/svc_xprt.c
>>> index bf5b5cd..92ca5c6 100644
>>> --- a/net/sunrpc/svc_xprt.c
>>> +++ b/net/sunrpc/svc_xprt.c
>>> @@ -837,6 +837,11 @@ static void svc_age_temp_xprts(unsigned long closure)
>>>  void svc_delete_xprt(struct svc_xprt *xprt)
>>>  {
>>>         struct svc_serv *serv = xprt->xpt_server;
>>> +       struct svc_deferred_req *dr;
>>> +
>>> +       /* Only do this once */
>>> +       if (test_and_set_bit(XPT_DEAD, &xprt->xpt_flags))
>>> +               return;
>>>
>>>         dprintk("svc: svc_delete_xprt(%p)\n", xprt);
>>>         xprt->xpt_ops->xpo_detach(xprt);
>>> @@ -851,12 +856,16 @@ void svc_delete_xprt(struct svc_xprt *xprt)
>>>          * while still attached to a queue, the queue itself
>>>          * is about to be destroyed (in svc_destroy).
>>>          */
>>> -       if (!test_and_set_bit(XPT_DEAD, &xprt->xpt_flags)) {
>>> -               BUG_ON(atomic_read(&xprt->xpt_ref.refcount) < 2);
>>> -               if (test_bit(XPT_TEMP, &xprt->xpt_flags))
>>> -                       serv->sv_tmpcnt--;
>>> +       if (test_bit(XPT_TEMP, &xprt->xpt_flags))
>>> +               serv->sv_tmpcnt--;
>>> +
>>> +       for (dr = svc_deferred_dequeue(xprt); dr;
>>> +            dr = svc_deferred_dequeue(xprt)) {
>>>                 svc_xprt_put(xprt);
>>> +               kfree(dr);
>>>         }
>>> +
>>> +       svc_xprt_put(xprt);
>>>         spin_unlock_bh(&serv->sv_lock);
>>>  }
>>>
>>> @@ -902,7 +911,8 @@ static void svc_revisit(struct cache_deferred_req *dreq, int too_many)
>>>                 container_of(dreq, struct svc_deferred_req, handle);
>>>         struct svc_xprt *xprt = dr->xprt;
>>>
>>> -       if (too_many) {
>>> +       if (too_many || test_bit(XPT_DEAD, &xprt->xpt_flags)) {
>>> +               dprintk("revisit cancelled\n");
>>>                 svc_xprt_put(xprt);
>>>                 kfree(dr);
>>>                 return;
>>>
>> I see nothing that stops svc_delete_xprt() from setting XPT_DEAD after
>> the above test in svc_revisit(), and before the test inside
>> svc_xprt_enqueue(). What's preventing a race there?
> 
> I suppose one way to fix it would be to hold the xprt->xpt_lock across
> the above test, and to make sure that you set XPT_DEFERRED while holding
> the lock, and _before_ you test for XPT_DEAD. That way, you guarantee
> that the svc_deferred_dequeue() loop in svc_delete_xprt() will pick up
> anything that races with the setting of XPT_DEAD.
> 

Yes, see previous post. Thanks Trond.


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

Re: [PATCH 3/3] SUNRPC: svc_xprt_enqueue should not refuse to enqueue 'XPT_DEAD' transports

[Tom Tucker]

Trond Myklebust wrote:
> On Sun, 2009-01-04 at 14:12 -0500, Trond Myklebust wrote:
[...snip...]

>> I see nothing that stops svc_delete_xprt() from setting XPT_DEAD after
>> the above test in svc_revisit(), and before the test inside
>> svc_xprt_enqueue(). What's preventing a race there?
> 
> I suppose one way to fix it would be to hold the xprt->xpt_lock across
> the above test, and to make sure that you set XPT_DEFERRED while holding
> the lock, and _before_ you test for XPT_DEAD. That way, you guarantee
> that the svc_deferred_dequeue() loop in svc_delete_xprt() will pick up
> anything that races with the setting of XPT_DEAD.
> 
> Trond

I think this patch fixes this. Thanks again,

From: Tom Tucker <tom@opengridcomputing.com>
Date: Mon, 5 Jan 2009 10:56:03 -0600
Subject: [PATCH] svc: Clean up deferred requests on transport destruction

A race between svc_revisit and svc_delete_xprt can result in
deferred requests holding references on a transport that can never be
recovered because dead transports are not enqueued for subsequent
processing.

Check for XPT_DEAD in revisit to clean up completing deferrals on a dead
transport and sweep a transport's deferred queue to do the same for queued
but unprocessed deferrals.

Signed-off-by: Tom Tucker <tom@opengridcomputing.com>

---
  net/sunrpc/svc_xprt.c |   29 ++++++++++++++++++++++-------
  1 files changed, 22 insertions(+), 7 deletions(-)

diff --git a/net/sunrpc/svc_xprt.c b/net/sunrpc/svc_xprt.c
index bf5b5cd..375a695 100644
--- a/net/sunrpc/svc_xprt.c
+++ b/net/sunrpc/svc_xprt.c
@@ -837,6 +837,15 @@ static void svc_age_temp_xprts(unsigned long closure)
  void svc_delete_xprt(struct svc_xprt *xprt)
  {
         struct svc_serv *serv = xprt->xpt_server;
+       struct svc_deferred_req *dr;
+
+       /* Only do this once */
+       spin_lock(&xprt->xpt_lock);
+       if (test_and_set_bit(XPT_DEAD, &xprt->xpt_flags)) {
+               spin_unlock(&xprt->xpt_lock);
+               return;
+       }
+       spin_unlock(&xprt->xpt_lock);

         dprintk("svc: svc_delete_xprt(%p)\n", xprt);
         xprt->xpt_ops->xpo_detach(xprt);
@@ -851,12 +860,16 @@ void svc_delete_xprt(struct svc_xprt *xprt)
          * while still attached to a queue, the queue itself
          * is about to be destroyed (in svc_destroy).
          */
-       if (!test_and_set_bit(XPT_DEAD, &xprt->xpt_flags)) {
-               BUG_ON(atomic_read(&xprt->xpt_ref.refcount) < 2);
-               if (test_bit(XPT_TEMP, &xprt->xpt_flags))
-                       serv->sv_tmpcnt--;
+       if (test_bit(XPT_TEMP, &xprt->xpt_flags))
+               serv->sv_tmpcnt--;
+
+       for (dr = svc_deferred_dequeue(xprt); dr;
+            dr = svc_deferred_dequeue(xprt)) {
                 svc_xprt_put(xprt);
+               kfree(dr);
         }
+
+       svc_xprt_put(xprt);
         spin_unlock_bh(&serv->sv_lock);
  }

@@ -902,17 +915,19 @@ static void svc_revisit(struct cache_deferred_req *dreq, int too_many)
                 container_of(dreq, struct svc_deferred_req, handle);
         struct svc_xprt *xprt = dr->xprt;

-       if (too_many) {
+       spin_lock(&xprt->xpt_lock);
+       if (too_many || test_bit(XPT_DEAD, &xprt->xpt_flags)) {
+               spin_unlock(&xprt->xpt_lock);
+               dprintk("revisit cancelled\n");
                 svc_xprt_put(xprt);
                 kfree(dr);
                 return;
         }
         dprintk("revisit queued\n");
         dr->xprt = NULL;
-       spin_lock(&xprt->xpt_lock);
         list_add(&dr->handle.recent, &xprt->xpt_deferred);
-       spin_unlock(&xprt->xpt_lock);
         set_bit(XPT_DEFERRED, &xprt->xpt_flags);
+       spin_unlock(&xprt->xpt_lock);
         svc_xprt_enqueue(xprt);
         svc_xprt_put(xprt);
  }

Re: [PATCH 3/3] SUNRPC: svc_xprt_enqueue should not refuse to enqueue 'XPT_DEAD' transports

[Trond Myklebust]

On Mon, 2009-01-05 at 11:04 -0600, Tom Tucker wrote:
> Trond Myklebust wrote:
> > On Sun, 2009-01-04 at 14:12 -0500, Trond Myklebust wrote:
> [...snip...]
> 
> >> I see nothing that stops svc_delete_xprt() from setting XPT_DEAD after
> >> the above test in svc_revisit(), and before the test inside
> >> svc_xprt_enqueue(). What's preventing a race there?
> > 
> > I suppose one way to fix it would be to hold the xprt->xpt_lock across
> > the above test, and to make sure that you set XPT_DEFERRED while holding
> > the lock, and _before_ you test for XPT_DEAD. That way, you guarantee
> > that the svc_deferred_dequeue() loop in svc_delete_xprt() will pick up
> > anything that races with the setting of XPT_DEAD.
> > 
> > Trond
> 
> I think this patch fixes this. Thanks again,
> 
> From: Tom Tucker <tom@opengridcomputing.com>
> Date: Mon, 5 Jan 2009 10:56:03 -0600
> Subject: [PATCH] svc: Clean up deferred requests on transport destruction
> 
> A race between svc_revisit and svc_delete_xprt can result in
> deferred requests holding references on a transport that can never be
> recovered because dead transports are not enqueued for subsequent
> processing.
> 
> Check for XPT_DEAD in revisit to clean up completing deferrals on a dead
> transport and sweep a transport's deferred queue to do the same for queued
> but unprocessed deferrals.
> 
> Signed-off-by: Tom Tucker <tom@opengridcomputing.com>
> 
> ---
>   net/sunrpc/svc_xprt.c |   29 ++++++++++++++++++++++-------
>   1 files changed, 22 insertions(+), 7 deletions(-)
> 
> diff --git a/net/sunrpc/svc_xprt.c b/net/sunrpc/svc_xprt.c
> index bf5b5cd..375a695 100644
> --- a/net/sunrpc/svc_xprt.c
> +++ b/net/sunrpc/svc_xprt.c
> @@ -837,6 +837,15 @@ static void svc_age_temp_xprts(unsigned long closure)
>   void svc_delete_xprt(struct svc_xprt *xprt)
>   {
>          struct svc_serv *serv = xprt->xpt_server;
> +       struct svc_deferred_req *dr;
> +
> +       /* Only do this once */
> +       spin_lock(&xprt->xpt_lock);
> +       if (test_and_set_bit(XPT_DEAD, &xprt->xpt_flags)) {
> +               spin_unlock(&xprt->xpt_lock);
> +               return;
> +       }
> +       spin_unlock(&xprt->xpt_lock);

You shouldn't need to take the spinlock here if you just move the line
	set_bit(XPT_DEFERRED, &xprt->xpt_flags);
in svc_revisit(). See below...

>          dprintk("svc: svc_delete_xprt(%p)\n", xprt);
>          xprt->xpt_ops->xpo_detach(xprt);
> @@ -851,12 +860,16 @@ void svc_delete_xprt(struct svc_xprt *xprt)
>           * while still attached to a queue, the queue itself
>           * is about to be destroyed (in svc_destroy).
>           */
> -       if (!test_and_set_bit(XPT_DEAD, &xprt->xpt_flags)) {
> -               BUG_ON(atomic_read(&xprt->xpt_ref.refcount) < 2);
> -               if (test_bit(XPT_TEMP, &xprt->xpt_flags))
> -                       serv->sv_tmpcnt--;
> +       if (test_bit(XPT_TEMP, &xprt->xpt_flags))
> +               serv->sv_tmpcnt--;
> +
> +       for (dr = svc_deferred_dequeue(xprt); dr;
> +            dr = svc_deferred_dequeue(xprt)) {
>                  svc_xprt_put(xprt);
> +               kfree(dr);
>          }
> +
> +       svc_xprt_put(xprt);
>          spin_unlock_bh(&serv->sv_lock);
>   }
> 
> @@ -902,17 +915,19 @@ static void svc_revisit(struct cache_deferred_req *dreq, int too_many)
>                  container_of(dreq, struct svc_deferred_req, handle);
>          struct svc_xprt *xprt = dr->xprt;
> 
> -       if (too_many) {
> +       spin_lock(&xprt->xpt_lock);

 +        set_bit(XPT_DEFERRED, &xprt->xpt_flags);


> +       if (too_many || test_bit(XPT_DEAD, &xprt->xpt_flags)) {
> +               spin_unlock(&xprt->xpt_lock);
> +               dprintk("revisit cancelled\n");
>                  svc_xprt_put(xprt);
>                  kfree(dr);
>                  return;
>          }
>          dprintk("revisit queued\n");
>          dr->xprt = NULL;
> -       spin_lock(&xprt->xpt_lock);
>          list_add(&dr->handle.recent, &xprt->xpt_deferred);
> -       spin_unlock(&xprt->xpt_lock);
>          set_bit(XPT_DEFERRED, &xprt->xpt_flags);

 -        set_bit(XPT_DEFERRED, &xprt->xpt_flags);

> +       spin_unlock(&xprt->xpt_lock);
>          svc_xprt_enqueue(xprt);
>          svc_xprt_put(xprt);
>   }

Re: [PATCH 3/3] SUNRPC: svc_xprt_enqueue should not refuse to enqueue 'XPT_DEAD' transports

[Tom Tucker]

Trond Myklebust wrote:
> On Mon, 2009-01-05 at 11:04 -0600, Tom Tucker wrote:
>> Trond Myklebust wrote:
>>> On Sun, 2009-01-04 at 14:12 -0500, Trond Myklebust wrote:
>> [...snip...]
>>
>>>> I see nothing that stops svc_delete_xprt() from setting XPT_DEAD after
>>>> the above test in svc_revisit(), and before the test inside
>>>> svc_xprt_enqueue(). What's preventing a race there?
>>> I suppose one way to fix it would be to hold the xprt->xpt_lock across
>>> the above test, and to make sure that you set XPT_DEFERRED while holding
>>> the lock, and _before_ you test for XPT_DEAD. That way, you guarantee
>>> that the svc_deferred_dequeue() loop in svc_delete_xprt() will pick up
>>> anything that races with the setting of XPT_DEAD.
>>>
>>> Trond
>> I think this patch fixes this. Thanks again,
>>
>> From: Tom Tucker <tom@opengridcomputing.com>
>> Date: Mon, 5 Jan 2009 10:56:03 -0600
>> Subject: [PATCH] svc: Clean up deferred requests on transport destruction
>>
>> A race between svc_revisit and svc_delete_xprt can result in
>> deferred requests holding references on a transport that can never be
>> recovered because dead transports are not enqueued for subsequent
>> processing.
>>
>> Check for XPT_DEAD in revisit to clean up completing deferrals on a dead
>> transport and sweep a transport's deferred queue to do the same for queued
>> but unprocessed deferrals.
>>
>> Signed-off-by: Tom Tucker <tom@opengridcomputing.com>
>>
>> ---
>>   net/sunrpc/svc_xprt.c |   29 ++++++++++++++++++++++-------
>>   1 files changed, 22 insertions(+), 7 deletions(-)
>>
>> diff --git a/net/sunrpc/svc_xprt.c b/net/sunrpc/svc_xprt.c
>> index bf5b5cd..375a695 100644
>> --- a/net/sunrpc/svc_xprt.c
>> +++ b/net/sunrpc/svc_xprt.c
>> @@ -837,6 +837,15 @@ static void svc_age_temp_xprts(unsigned long closure)
>>   void svc_delete_xprt(struct svc_xprt *xprt)
>>   {
>>          struct svc_serv *serv = xprt->xpt_server;
>> +       struct svc_deferred_req *dr;
>> +
>> +       /* Only do this once */
>> +       spin_lock(&xprt->xpt_lock);
>> +       if (test_and_set_bit(XPT_DEAD, &xprt->xpt_flags)) {
>> +               spin_unlock(&xprt->xpt_lock);
>> +               return;
>> +       }
>> +       spin_unlock(&xprt->xpt_lock);
> 
> You shouldn't need to take the spinlock here if you just move the line
> 	set_bit(XPT_DEFERRED, &xprt->xpt_flags);
> in svc_revisit(). See below...
> 

I'm confused...sorry.

This lock in intended to avoid the following race:

				revisit:
					- test_bit == 0
svc_delete_xprt:
	- test_and_set_bit == 0
	- iterates over deferred queue,
	  but there's nothing in it yet
	  to clean up.

					- Adds deferred request to transport's
					  deferred list.
					- enqueue fails because XPT_DEAD is set

Now we've got a dangling reference.

The lock forces the delete to wait until the revisit had
added the deferral to the transport list.


>>          dprintk("svc: svc_delete_xprt(%p)\n", xprt);
>>          xprt->xpt_ops->xpo_detach(xprt);
>> @@ -851,12 +860,16 @@ void svc_delete_xprt(struct svc_xprt *xprt)
>>           * while still attached to a queue, the queue itself
>>           * is about to be destroyed (in svc_destroy).
>>           */
>> -       if (!test_and_set_bit(XPT_DEAD, &xprt->xpt_flags)) {
>> -               BUG_ON(atomic_read(&xprt->xpt_ref.refcount) < 2);
>> -               if (test_bit(XPT_TEMP, &xprt->xpt_flags))
>> -                       serv->sv_tmpcnt--;
>> +       if (test_bit(XPT_TEMP, &xprt->xpt_flags))
>> +               serv->sv_tmpcnt--;
>> +
>> +       for (dr = svc_deferred_dequeue(xprt); dr;
>> +            dr = svc_deferred_dequeue(xprt)) {
>>                  svc_xprt_put(xprt);
>> +               kfree(dr);
>>          }
>> +
>> +       svc_xprt_put(xprt);
>>          spin_unlock_bh(&serv->sv_lock);
>>   }
>>
>> @@ -902,17 +915,19 @@ static void svc_revisit(struct cache_deferred_req *dreq, int too_many)
>>                  container_of(dreq, struct svc_deferred_req, handle);
>>          struct svc_xprt *xprt = dr->xprt;
>>
>> -       if (too_many) {
>> +       spin_lock(&xprt->xpt_lock);
> 
>  +        set_bit(XPT_DEFERRED, &xprt->xpt_flags);
> 

Given the above, how does this avoid the race?

Thanks,
Tom

> 
>> +       if (too_many || test_bit(XPT_DEAD, &xprt->xpt_flags)) {
>> +               spin_unlock(&xprt->xpt_lock);
>> +               dprintk("revisit cancelled\n");
>>                  svc_xprt_put(xprt);
>>                  kfree(dr);
>>                  return;
>>          }
>>          dprintk("revisit queued\n");
>>          dr->xprt = NULL;
>> -       spin_lock(&xprt->xpt_lock);
>>          list_add(&dr->handle.recent, &xprt->xpt_deferred);
>> -       spin_unlock(&xprt->xpt_lock);
>>          set_bit(XPT_DEFERRED, &xprt->xpt_flags);
> 
>  -        set_bit(XPT_DEFERRED, &xprt->xpt_flags);
> 
>> +       spin_unlock(&xprt->xpt_lock);
>>          svc_xprt_enqueue(xprt);
>>          svc_xprt_put(xprt);
>>   }
> 
> --
> To unsubscribe from this list: send the line "unsubscribe linux-nfs" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [PATCH 3/3] SUNRPC: svc_xprt_enqueue should not refuse to enqueue 'XPT_DEAD' transports

[Trond Myklebust]

On Mon, 2009-01-05 at 13:33 -0600, Tom Tucker wrote:
> Trond Myklebust wrote:
> > On Mon, 2009-01-05 at 11:04 -0600, Tom Tucker wrote:
> >> Trond Myklebust wrote:
> >>> On Sun, 2009-01-04 at 14:12 -0500, Trond Myklebust wrote:
> >> [...snip...]
> >>
> >>>> I see nothing that stops svc_delete_xprt() from setting XPT_DEAD after
> >>>> the above test in svc_revisit(), and before the test inside
> >>>> svc_xprt_enqueue(). What's preventing a race there?
> >>> I suppose one way to fix it would be to hold the xprt->xpt_lock across
> >>> the above test, and to make sure that you set XPT_DEFERRED while holding
> >>> the lock, and _before_ you test for XPT_DEAD. That way, you guarantee
> >>> that the svc_deferred_dequeue() loop in svc_delete_xprt() will pick up
> >>> anything that races with the setting of XPT_DEAD.
> >>>
> >>> Trond
> >> I think this patch fixes this. Thanks again,
> >>
> >> From: Tom Tucker <tom@opengridcomputing.com>
> >> Date: Mon, 5 Jan 2009 10:56:03 -0600
> >> Subject: [PATCH] svc: Clean up deferred requests on transport destruction
> >>
> >> A race between svc_revisit and svc_delete_xprt can result in
> >> deferred requests holding references on a transport that can never be
> >> recovered because dead transports are not enqueued for subsequent
> >> processing.
> >>
> >> Check for XPT_DEAD in revisit to clean up completing deferrals on a dead
> >> transport and sweep a transport's deferred queue to do the same for queued
> >> but unprocessed deferrals.
> >>
> >> Signed-off-by: Tom Tucker <tom@opengridcomputing.com>
> >>
> >> ---
> >>   net/sunrpc/svc_xprt.c |   29 ++++++++++++++++++++++-------
> >>   1 files changed, 22 insertions(+), 7 deletions(-)
> >>
> >> diff --git a/net/sunrpc/svc_xprt.c b/net/sunrpc/svc_xprt.c
> >> index bf5b5cd..375a695 100644
> >> --- a/net/sunrpc/svc_xprt.c
> >> +++ b/net/sunrpc/svc_xprt.c
> >> @@ -837,6 +837,15 @@ static void svc_age_temp_xprts(unsigned long closure)
> >>   void svc_delete_xprt(struct svc_xprt *xprt)
> >>   {
> >>          struct svc_serv *serv = xprt->xpt_server;
> >> +       struct svc_deferred_req *dr;
> >> +
> >> +       /* Only do this once */
> >> +       spin_lock(&xprt->xpt_lock);
> >> +       if (test_and_set_bit(XPT_DEAD, &xprt->xpt_flags)) {
> >> +               spin_unlock(&xprt->xpt_lock);
> >> +               return;
> >> +       }
> >> +       spin_unlock(&xprt->xpt_lock);
> > 
> > You shouldn't need to take the spinlock here if you just move the line
> > 	set_bit(XPT_DEFERRED, &xprt->xpt_flags);
> > in svc_revisit(). See below...
> > 
> 
> I'm confused...sorry.
> 
> This lock in intended to avoid the following race:
> 
> 				revisit:
> 					- test_bit == 0
> svc_delete_xprt:
> 	- test_and_set_bit == 0
> 	- iterates over deferred queue,
> 	  but there's nothing in it yet
> 	  to clean up.
> 
> 					- Adds deferred request to transport's
> 					  deferred list.
> 					- enqueue fails because XPT_DEAD is set
> 
> Now we've got a dangling reference.
> 
> The lock forces the delete to wait until the revisit had
> added the deferral to the transport list.
> 
> 
> >>          dprintk("svc: svc_delete_xprt(%p)\n", xprt);
> >>          xprt->xpt_ops->xpo_detach(xprt);
> >> @@ -851,12 +860,16 @@ void svc_delete_xprt(struct svc_xprt *xprt)
> >>           * while still attached to a queue, the queue itself
> >>           * is about to be destroyed (in svc_destroy).
> >>           */
> >> -       if (!test_and_set_bit(XPT_DEAD, &xprt->xpt_flags)) {
> >> -               BUG_ON(atomic_read(&xprt->xpt_ref.refcount) < 2);
> >> -               if (test_bit(XPT_TEMP, &xprt->xpt_flags))
> >> -                       serv->sv_tmpcnt--;
> >> +       if (test_bit(XPT_TEMP, &xprt->xpt_flags))
> >> +               serv->sv_tmpcnt--;
> >> +
> >> +       for (dr = svc_deferred_dequeue(xprt); dr;
> >> +            dr = svc_deferred_dequeue(xprt)) {
> >>                  svc_xprt_put(xprt);
> >> +               kfree(dr);
> >>          }
> >> +
> >> +       svc_xprt_put(xprt);
> >>          spin_unlock_bh(&serv->sv_lock);
> >>   }
> >>
> >> @@ -902,17 +915,19 @@ static void svc_revisit(struct cache_deferred_req *dreq, int too_many)
> >>                  container_of(dreq, struct svc_deferred_req, handle);
> >>          struct svc_xprt *xprt = dr->xprt;
> >>
> >> -       if (too_many) {
> >> +       spin_lock(&xprt->xpt_lock);
> > 
> >  +        set_bit(XPT_DEFERRED, &xprt->xpt_flags);
> > 
> 
> Given the above, how does this avoid the race?

By setting XPT_DEFERRED, you will force svc_deferred_dequeue to wait for
the xprt->xpt_lock, which you are already holding. At that point, it
would be OK for the test of XPT_DEAD to race, since you are still
holding the xpt_lock, so the loop over svc_deferred_dequeue() will catch
it...

Cheers
  Trond

Re: [PATCH 3/3] SUNRPC: svc_xprt_enqueue should not refuse to enqueue 'XPT_DEAD' transports

[Tom Tucker]

Trond Myklebust wrote:
> On Mon, 2009-01-05 at 13:33 -0600, Tom Tucker wrote:
>> Trond Myklebust wrote:
>>> On Mon, 2009-01-05 at 11:04 -0600, Tom Tucker wrote:
>>>> Trond Myklebust wrote:
>>>>> On Sun, 2009-01-04 at 14:12 -0500, Trond Myklebust wrote:
>>>> [...snip...]
>>>>
>>>>>> I see nothing that stops svc_delete_xprt() from setting XPT_DEAD after
>>>>>> the above test in svc_revisit(), and before the test inside
>>>>>> svc_xprt_enqueue(). What's preventing a race there?
>>>>> I suppose one way to fix it would be to hold the xprt->xpt_lock across
>>>>> the above test, and to make sure that you set XPT_DEFERRED while holding
>>>>> the lock, and _before_ you test for XPT_DEAD. That way, you guarantee
>>>>> that the svc_deferred_dequeue() loop in svc_delete_xprt() will pick up
>>>>> anything that races with the setting of XPT_DEAD.
>>>>>
>>>>> Trond
>>>> I think this patch fixes this. Thanks again,
>>>>
>>>> From: Tom Tucker <tom@opengridcomputing.com>
>>>> Date: Mon, 5 Jan 2009 10:56:03 -0600
>>>> Subject: [PATCH] svc: Clean up deferred requests on transport destruction
>>>>
>>>> A race between svc_revisit and svc_delete_xprt can result in
>>>> deferred requests holding references on a transport that can never be
>>>> recovered because dead transports are not enqueued for subsequent
>>>> processing.
>>>>
>>>> Check for XPT_DEAD in revisit to clean up completing deferrals on a dead
>>>> transport and sweep a transport's deferred queue to do the same for queued
>>>> but unprocessed deferrals.
>>>>
>>>> Signed-off-by: Tom Tucker <tom@opengridcomputing.com>
>>>>
>>>> ---
>>>>   net/sunrpc/svc_xprt.c |   29 ++++++++++++++++++++++-------
>>>>   1 files changed, 22 insertions(+), 7 deletions(-)
>>>>
>>>> diff --git a/net/sunrpc/svc_xprt.c b/net/sunrpc/svc_xprt.c
>>>> index bf5b5cd..375a695 100644
>>>> --- a/net/sunrpc/svc_xprt.c
>>>> +++ b/net/sunrpc/svc_xprt.c
>>>> @@ -837,6 +837,15 @@ static void svc_age_temp_xprts(unsigned long closure)
>>>>   void svc_delete_xprt(struct svc_xprt *xprt)
>>>>   {
>>>>          struct svc_serv *serv = xprt->xpt_server;
>>>> +       struct svc_deferred_req *dr;
>>>> +
>>>> +       /* Only do this once */
>>>> +       spin_lock(&xprt->xpt_lock);
>>>> +       if (test_and_set_bit(XPT_DEAD, &xprt->xpt_flags)) {
>>>> +               spin_unlock(&xprt->xpt_lock);
>>>> +               return;
>>>> +       }
>>>> +       spin_unlock(&xprt->xpt_lock);
>>> You shouldn't need to take the spinlock here if you just move the line
>>> 	set_bit(XPT_DEFERRED, &xprt->xpt_flags);
>>> in svc_revisit(). See below...
>>>
>> I'm confused...sorry.
>>
>> This lock in intended to avoid the following race:
>>
>> 				revisit:
>> 					- test_bit == 0
>> svc_delete_xprt:
>> 	- test_and_set_bit == 0
>> 	- iterates over deferred queue,
>> 	  but there's nothing in it yet
>> 	  to clean up.
>>
>> 					- Adds deferred request to transport's
>> 					  deferred list.
>> 					- enqueue fails because XPT_DEAD is set
>>
>> Now we've got a dangling reference.
>>
>> The lock forces the delete to wait until the revisit had
>> added the deferral to the transport list.
>>
>>
>>>>          dprintk("svc: svc_delete_xprt(%p)\n", xprt);
>>>>          xprt->xpt_ops->xpo_detach(xprt);
>>>> @@ -851,12 +860,16 @@ void svc_delete_xprt(struct svc_xprt *xprt)
>>>>           * while still attached to a queue, the queue itself
>>>>           * is about to be destroyed (in svc_destroy).
>>>>           */
>>>> -       if (!test_and_set_bit(XPT_DEAD, &xprt->xpt_flags)) {
>>>> -               BUG_ON(atomic_read(&xprt->xpt_ref.refcount) < 2);
>>>> -               if (test_bit(XPT_TEMP, &xprt->xpt_flags))
>>>> -                       serv->sv_tmpcnt--;
>>>> +       if (test_bit(XPT_TEMP, &xprt->xpt_flags))
>>>> +               serv->sv_tmpcnt--;
>>>> +
>>>> +       for (dr = svc_deferred_dequeue(xprt); dr;
>>>> +            dr = svc_deferred_dequeue(xprt)) {
>>>>                  svc_xprt_put(xprt);
>>>> +               kfree(dr);
>>>>          }
>>>> +
>>>> +       svc_xprt_put(xprt);
>>>>          spin_unlock_bh(&serv->sv_lock);
>>>>   }
>>>>
>>>> @@ -902,17 +915,19 @@ static void svc_revisit(struct cache_deferred_req *dreq, int too_many)
>>>>                  container_of(dreq, struct svc_deferred_req, handle);
>>>>          struct svc_xprt *xprt = dr->xprt;
>>>>
>>>> -       if (too_many) {
>>>> +       spin_lock(&xprt->xpt_lock);
>>>  +        set_bit(XPT_DEFERRED, &xprt->xpt_flags);
>>>
>> Given the above, how does this avoid the race?
> 
> By setting XPT_DEFERRED, you will force svc_deferred_dequeue to wait for
> the xprt->xpt_lock, which you are already holding. At that point, it
> would be OK for the test of XPT_DEAD to race, since you are still
> holding the xpt_lock, so the loop over svc_deferred_dequeue() will catch
> it...
> 

Right. I should have looked more carefully.


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

Re: [PATCH 3/3] SUNRPC: svc_xprt_enqueue should not refuse to enqueue 'XPT_DEAD' transports

[Tom Tucker]

Trond Myklebust wrote:
> On Mon, 2009-01-05 at 13:33 -0600, Tom Tucker wrote:
>> Trond Myklebust wrote:
>>> On Mon, 2009-01-05 at 11:04 -0600, Tom Tucker wrote:
>>>> Trond Myklebust wrote:
>>>>> On Sun, 2009-01-04 at 14:12 -0500, Trond Myklebust wrote:
>>>> [...snip...]
>>>>
>>>>>> I see nothing that stops svc_delete_xprt() from setting XPT_DEAD after
>>>>>> the above test in svc_revisit(), and before the test inside
>>>>>> svc_xprt_enqueue(). What's preventing a race there?
>>>>> I suppose one way to fix it would be to hold the xprt->xpt_lock across
>>>>> the above test, and to make sure that you set XPT_DEFERRED while holding
>>>>> the lock, and _before_ you test for XPT_DEAD. That way, you guarantee
>>>>> that the svc_deferred_dequeue() loop in svc_delete_xprt() will pick up
>>>>> anything that races with the setting of XPT_DEAD.
>>>>>
>>>>> Trond
>>>> I think this patch fixes this. Thanks again,
>>>>
>>>> From: Tom Tucker <tom@opengridcomputing.com>
>>>> Date: Mon, 5 Jan 2009 10:56:03 -0600
>>>> Subject: [PATCH] svc: Clean up deferred requests on transport destruction
>>>>
>>>> A race between svc_revisit and svc_delete_xprt can result in
>>>> deferred requests holding references on a transport that can never be
>>>> recovered because dead transports are not enqueued for subsequent
>>>> processing.
>>>>
>>>> Check for XPT_DEAD in revisit to clean up completing deferrals on a dead
>>>> transport and sweep a transport's deferred queue to do the same for queued
>>>> but unprocessed deferrals.
>>>>
>>>> Signed-off-by: Tom Tucker <tom@opengridcomputing.com>
>>>>
>>>> ---
>>>>   net/sunrpc/svc_xprt.c |   29 ++++++++++++++++++++++-------
>>>>   1 files changed, 22 insertions(+), 7 deletions(-)
>>>>
>>>> diff --git a/net/sunrpc/svc_xprt.c b/net/sunrpc/svc_xprt.c
>>>> index bf5b5cd..375a695 100644
>>>> --- a/net/sunrpc/svc_xprt.c
>>>> +++ b/net/sunrpc/svc_xprt.c
>>>> @@ -837,6 +837,15 @@ static void svc_age_temp_xprts(unsigned long closure)
>>>>   void svc_delete_xprt(struct svc_xprt *xprt)
>>>>   {
>>>>          struct svc_serv *serv = xprt->xpt_server;
>>>> +       struct svc_deferred_req *dr;
>>>> +
>>>> +       /* Only do this once */
>>>> +       spin_lock(&xprt->xpt_lock);
>>>> +       if (test_and_set_bit(XPT_DEAD, &xprt->xpt_flags)) {
>>>> +               spin_unlock(&xprt->xpt_lock);
>>>> +               return;
>>>> +       }
>>>> +       spin_unlock(&xprt->xpt_lock);
>>> You shouldn't need to take the spinlock here if you just move the line
>>> 	set_bit(XPT_DEFERRED, &xprt->xpt_flags);
>>> in svc_revisit(). See below...
>>>
>> I'm confused...sorry.
>>
>> This lock in intended to avoid the following race:
>>
>> 				revisit:
>> 					- test_bit == 0
>> svc_delete_xprt:
>> 	- test_and_set_bit == 0
>> 	- iterates over deferred queue,
>> 	  but there's nothing in it yet
>> 	  to clean up.
>>
>> 					- Adds deferred request to transport's
>> 					  deferred list.
>> 					- enqueue fails because XPT_DEAD is set
>>
>> Now we've got a dangling reference.
>>
>> The lock forces the delete to wait until the revisit had
>> added the deferral to the transport list.
>>
>>
>>>>          dprintk("svc: svc_delete_xprt(%p)\n", xprt);
>>>>          xprt->xpt_ops->xpo_detach(xprt);
>>>> @@ -851,12 +860,16 @@ void svc_delete_xprt(struct svc_xprt *xprt)
>>>>           * while still attached to a queue, the queue itself
>>>>           * is about to be destroyed (in svc_destroy).
>>>>           */
>>>> -       if (!test_and_set_bit(XPT_DEAD, &xprt->xpt_flags)) {
>>>> -               BUG_ON(atomic_read(&xprt->xpt_ref.refcount) < 2);
>>>> -               if (test_bit(XPT_TEMP, &xprt->xpt_flags))
>>>> -                       serv->sv_tmpcnt--;
>>>> +       if (test_bit(XPT_TEMP, &xprt->xpt_flags))
>>>> +               serv->sv_tmpcnt--;
>>>> +
>>>> +       for (dr = svc_deferred_dequeue(xprt); dr;
>>>> +            dr = svc_deferred_dequeue(xprt)) {
>>>>                  svc_xprt_put(xprt);
>>>> +               kfree(dr);
>>>>          }
>>>> +
>>>> +       svc_xprt_put(xprt);
>>>>          spin_unlock_bh(&serv->sv_lock);
>>>>   }
>>>>
>>>> @@ -902,17 +915,19 @@ static void svc_revisit(struct cache_deferred_req *dreq, int too_many)
>>>>                  container_of(dreq, struct svc_deferred_req, handle);
>>>>          struct svc_xprt *xprt = dr->xprt;
>>>>
>>>> -       if (too_many) {
>>>> +       spin_lock(&xprt->xpt_lock);
>>>  +        set_bit(XPT_DEFERRED, &xprt->xpt_flags);
>>>
>> Given the above, how does this avoid the race?
> 
> By setting XPT_DEFERRED, you will force svc_deferred_dequeue to wait for
> the xprt->xpt_lock, which you are already holding. At that point, it
> would be OK for the test of XPT_DEAD to race, since you are still
> holding the xpt_lock, so the loop over svc_deferred_dequeue() will catch
> it...
> 

Trond, this version removes the extra unnecessary spin locks.

If it's ok, do you want me to resend to Bruce, or
do you want to couple it with your other patch?

Thanks,
Tom

A race between svc_revisit and svc_delete_xprt can result in
deferred requests holding references on a transport that can never be
recovered because dead transports are not enqueued for subsequent
processing.

Check for XPT_DEAD in revisit to clean up completing deferrals on a dead
transport and sweep a transport's deferred queue to do the same for queued
but unprocessed deferrals.

Signed-off-by: Tom Tucker <tom@opengridcomputing.com>

---
  net/sunrpc/svc_xprt.c |   25 ++++++++++++++++++-------
  1 files changed, 18 insertions(+), 7 deletions(-)

diff --git a/net/sunrpc/svc_xprt.c b/net/sunrpc/svc_xprt.c
index bf5b5cd..6bdbb79 100644
--- a/net/sunrpc/svc_xprt.c
+++ b/net/sunrpc/svc_xprt.c
@@ -837,6 +837,11 @@ static void svc_age_temp_xprts(unsigned long closure)
  void svc_delete_xprt(struct svc_xprt *xprt)
  {
  	struct svc_serv	*serv = xprt->xpt_server;
+	struct svc_deferred_req *dr;
+
+	/* Only do this once */
+	if (test_and_set_bit(XPT_DEAD, &xprt->xpt_flags))
+		return;

  	dprintk("svc: svc_delete_xprt(%p)\n", xprt);
  	xprt->xpt_ops->xpo_detach(xprt);
@@ -851,12 +856,16 @@ void svc_delete_xprt(struct svc_xprt *xprt)
  	 * while still attached to a queue, the queue itself
  	 * is about to be destroyed (in svc_destroy).
  	 */
-	if (!test_and_set_bit(XPT_DEAD, &xprt->xpt_flags)) {
-		BUG_ON(atomic_read(&xprt->xpt_ref.refcount) < 2);
-		if (test_bit(XPT_TEMP, &xprt->xpt_flags))
-			serv->sv_tmpcnt--;
+	if (test_bit(XPT_TEMP, &xprt->xpt_flags))
+		serv->sv_tmpcnt--;
+
+	for (dr = svc_deferred_dequeue(xprt); dr;
+	     dr = svc_deferred_dequeue(xprt)) {
  		svc_xprt_put(xprt);
+		kfree(dr);
  	}
+
+	svc_xprt_put(xprt);
  	spin_unlock_bh(&serv->sv_lock);
  }

@@ -902,17 +911,19 @@ static void svc_revisit(struct cache_deferred_req *dreq, int too_many)
  		container_of(dreq, struct svc_deferred_req, handle);
  	struct svc_xprt *xprt = dr->xprt;

-	if (too_many) {
+	spin_lock(&xprt->xpt_lock);
+	set_bit(XPT_DEFERRED, &xprt->xpt_flags);
+	if (too_many || test_bit(XPT_DEAD, &xprt->xpt_flags)) {
+		spin_unlock(&xprt->xpt_lock);
+		dprintk("revisit cancelled\n");
  		svc_xprt_put(xprt);
  		kfree(dr);
  		return;
  	}
  	dprintk("revisit queued\n");
  	dr->xprt = NULL;
-	spin_lock(&xprt->xpt_lock);
  	list_add(&dr->handle.recent, &xprt->xpt_deferred);
  	spin_unlock(&xprt->xpt_lock);
-	set_bit(XPT_DEFERRED, &xprt->xpt_flags);
  	svc_xprt_enqueue(xprt);
  	svc_xprt_put(xprt);
  }


> Cheers
>   Trond
> 
> 

Re: [PATCH 3/3] SUNRPC: svc_xprt_enqueue should not refuse to enqueue 'XPT_DEAD' transports

[Trond Myklebust]

On Mon, 2009-01-05 at 14:41 -0600, Tom Tucker wrote:
> Trond, this version removes the extra unnecessary spin locks.
> 
> If it's ok, do you want me to resend to Bruce, or
> do you want to couple it with your other patch?

As long as it applies on top of my patch, then just send it on to Bruce.

Cheers
  Trond

Re: [PATCH 3/3] SUNRPC: svc_xprt_enqueue should not refuse to enqueue 'XPT_DEAD' transports

[Tom Tucker]

Trond Myklebust wrote:
> On Mon, 2009-01-05 at 14:41 -0600, Tom Tucker wrote:
>> Trond, this version removes the extra unnecessary spin locks.
>>
>> If it's ok, do you want me to resend to Bruce, or
>> do you want to couple it with your other patch?
> 
> As long as it applies on top of my patch, then just send it on to Bruce.
> 
> Cheers
>   Trond

This patch only touches svc_xprt.c and yours only touches svcsock.c,
so we're clean.

Thanks for your help,
Tom

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Trond Myklebust]

On Sun, 2008-11-30 at 19:17 -0500, Trond Myklebust wrote:
> Can you see if the following 3 patches help? They're against 2.6.28-rc6,
> but afaics the problems are pretty much the same on 2.6.26.
> 
> Cheers
>   Trond

Sorry... I forgot to add that these 3 patches need to be applied to the
nfs server, not the client.

Cheers
  Trond
-- 
Trond Myklebust
Linux NFS client maintainer

NetApp
Trond.Myklebust@netapp.com
www.netapp.com

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Kasparek Tomas]

On Sun, Nov 30, 2008 at 07:29:40PM -0500, Trond Myklebust wrote:
> On Sun, 2008-11-30 at 19:17 -0500, Trond Myklebust wrote:
> > Can you see if the following 3 patches help? They're against 2.6.28-rc6,
> > but afaics the problems are pretty much the same on 2.6.26.
> 
> Sorry... I forgot to add that these 3 patches need to be applied to the
> nfs server, not the client.

Hi,

I have the problem on client side and can not change server (FreeBSD 7.0). 
these patches does not change the situation (and they are probably not
supposed to do so, just giving it a try). After few minutes I got this on
the client with 2.6.28-rc6 with patches:

tcp   0   0 147.229.12.146:674          147.229.176.14:2049     FIN_WAIT2

Applying reverse e06799f958bf7f9f8fae15f0c6f519953fb0257c suggested by Ian
does help on the other side (with 2.6.27.4).

Bye

--   

  Tomas Kasparek, PhD student  E-mail: kasparek@fit.vutbr.cz
  CVT FIT VUT Brno, L127       Web:    http://www.fit.vutbr.cz/~kasparek
  Bozetechova 1, 612 66        Fax:    +420 54114-1270
  Brno, Czech Republic         Phone:  +420 54114-1220

  jabber: tomas.kasparek-2ASvDZBniIelVyrhU4qvOw@public.gmane.org
  GPG: 2F1E 1AAF FD3B CFA3 1537  63BD DCBE 18FF A035 53BC

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Trond Myklebust]

On Tue, 2008-12-02 at 16:22 +0100, Kasparek Tomas wrote:
> On Sun, Nov 30, 2008 at 07:29:40PM -0500, Trond Myklebust wrote:
> > On Sun, 2008-11-30 at 19:17 -0500, Trond Myklebust wrote:
> > > Can you see if the following 3 patches help? They're against 2.6.28-rc6,
> > > but afaics the problems are pretty much the same on 2.6.26.
> > 
> > Sorry... I forgot to add that these 3 patches need to be applied to the
> > nfs server, not the client.
> 
> Hi,
> 
> I have the problem on client side and can not change server (FreeBSD 7.0). 
> these patches does not change the situation (and they are probably not
> supposed to do so, just giving it a try). After few minutes I got this on
> the client with 2.6.28-rc6 with patches:
> 
> tcp   0   0 147.229.12.146:674          147.229.176.14:2049     FIN_WAIT2
> 
> Applying reverse e06799f958bf7f9f8fae15f0c6f519953fb0257c suggested by Ian
> does help on the other side (with 2.6.27.4).

Then I suggest working around the problem by reducing the value of the
sysctl net.ipv4.tcp_fin_timeout on the client.
-- 
Trond Myklebust
Linux NFS client maintainer

NetApp
Trond.Myklebust@netapp.com
www.netapp.com

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Kasparek Tomas]

On Tue, Dec 02, 2008 at 10:37:02AM -0500, Trond Myklebust wrote:
> On Tue, 2008-12-02 at 16:22 +0100, Kasparek Tomas wrote:
> > On Sun, Nov 30, 2008 at 07:29:40PM -0500, Trond Myklebust wrote:
> > > On Sun, 2008-11-30 at 19:17 -0500, Trond Myklebust wrote:
> > > > Can you see if the following 3 patches help? They're against 2.6.28-rc6,
> > > > but afaics the problems are pretty much the same on 2.6.26.
> > > 
> > > Sorry... I forgot to add that these 3 patches need to be applied to the
> > > nfs server, not the client.
> > 
> > Hi,
> > 
> > I have the problem on client side and can not change server (FreeBSD 7.0). 
> > these patches does not change the situation (and they are probably not
> > supposed to do so, just giving it a try). After few minutes I got this on
> > the client with 2.6.28-rc6 with patches:
> > 
> > tcp   0   0 147.229.12.146:674          147.229.176.14:2049     FIN_WAIT2
> > 
> > Applying reverse e06799f958bf7f9f8fae15f0c6f519953fb0257c suggested by Ian
> > does help on the other side (with 2.6.27.4).
> 
> Then I suggest working around the problem by reducing the value of the
> sysctl net.ipv4.tcp_fin_timeout on the client.

Did tried. The number should be seconds and defaults to 60, These
connections are still there after several hours. Changing it to 10 (sec)
and same behaviour. (BTW The server did not changed in last several months)

--   

  Tomas Kasparek, PhD student  E-mail: kasparek@fit.vutbr.cz
  CVT FIT VUT Brno, L127       Web:    http://www.fit.vutbr.cz/~kasparek
  Bozetechova 1, 612 66        Fax:    +420 54114-1270
  Brno, Czech Republic         Phone:  +420 54114-1220

  jabber: tomas.kasparek-2ASvDZBniIelVyrhU4qvOw@public.gmane.org
  GPG: 2F1E 1AAF FD3B CFA3 1537  63BD DCBE 18FF A035 53BC

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Trond Myklebust]

On Tue, 2008-12-02 at 17:26 +0100, Kasparek Tomas wrote:

> Did tried. The number should be seconds and defaults to 60, These
> connections are still there after several hours. Changing it to 10 (sec)
> and same behaviour. (BTW The server did not changed in last several months)

Are you seeing the same behaviour with 'netstat -t'?

-- 
Trond Myklebust
Linux NFS client maintainer

NetApp
Trond.Myklebust@netapp.com
www.netapp.com

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Kasparek Tomas]

On Tue, Dec 02, 2008 at 01:10:07PM -0500, Trond Myklebust wrote:
> On Tue, 2008-12-02 at 17:26 +0100, Kasparek Tomas wrote:
> 
> > Did tried. The number should be seconds and defaults to 60, These
> > connections are still there after several hours. Changing it to 10 (sec)
> > and same behaviour. (BTW The server did not changed in last several months)
> 
> Are you seeing the same behaviour with 'netstat -t'?

yes:

root@pckasparek: ~# ssh root@pcnlp1 'netstat -pan | grep WAIT' | cut -c-85
tcp    0   0 147.229.12.146:989          147.229.176.14:2049 FIN_WAIT2
root@pckasparek: ~# ssh root@pcnlp1 'netstat -t | grep WAIT' | cut -c-85
tcp    0   0 pcnlp1.fit.vutbr.:ftps-data eva.fit.vutbr.cz:nfs FIN_WAIT2

but it should be the same, did't it? -t just selects TCP connections and
this is TCP connection so it shows the same

--   

  Tomas Kasparek, PhD student  E-mail: kasparek@fit.vutbr.cz
  CVT FIT VUT Brno, L127       Web:    http://www.fit.vutbr.cz/~kasparek
  Bozetechova 1, 612 66        Fax:    +420 54114-1270
  Brno, Czech Republic         Phone:  +420 54114-1220

  jabber: tomas.kasparek-2ASvDZBniIelVyrhU4qvOw@public.gmane.org
  GPG: 2F1E 1AAF FD3B CFA3 1537  63BD DCBE 18FF A035 53BC

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Kasparek Tomas]

On Sun, Dec 14, 2008 at 02:50:01PM -0500, Trond Myklebust wrote:
> On Thu, 2008-12-04 at 11:23 +0100, Kasparek Tomas wrote:
> > On Tue, Dec 02, 2008 at 01:10:07PM -0500, Trond Myklebust wrote:
> > > On Tue, 2008-12-02 at 17:26 +0100, Kasparek Tomas wrote:
> > > 
> > > > Did tried. The number should be seconds and defaults to 60, These
> > > > connections are still there after several hours. Changing it to 10 (sec)
> > > > and same behaviour. (BTW The server did not changed in last several months)
> > > 
> > > Are you seeing the same behaviour with 'netstat -t'?
> > 
> > yes:
> > 
> > root@pckasparek: ~# ssh root@pcnlp1 'netstat -pan | grep WAIT' | cut -c-85
> > tcp    0   0 147.229.12.146:989          147.229.176.14:2049 FIN_WAIT2
> > root@pckasparek: ~# ssh root@pcnlp1 'netstat -t | grep WAIT' | cut -c-85
> > tcp    0   0 pcnlp1.fit.vutbr.:ftps-data eva.fit.vutbr.cz:nfs FIN_WAIT2
> > 
> > but it should be the same, did't it? -t just selects TCP connections and
> > this is TCP connection so it shows the same
> 
> Right, but the point is that the client is in the state FIN_WAIT2, which
> means that it has closed the socket on its end, and is waiting for the
> server to close on its end. The fact that the server is failing to do
> this is a server bug.
> 
> That said, we can't wait forever for buggy servers. I see now why the
> linger2 stuff isn't working. I believe that the appended patch should
> help...

Hm, not happy to say that but it still does not work after some time. Now
the problem is opposite there are no connections to the server according to
netstat on client, just time to time there is

pcnlp1.fit.vutbr.cz.15234 > kazi.fit.vutbr.cz.nfs: 40 null
kazi.fit.vutbr.cz.nfs > pcnlp1.fit.vutbr.cz.15234: reply ok 24 null

(kazi is server). Will try to investigate more details.

(just to remember the same kernel with reversed
e06799f958bf7f9f8fae15f0c6f519953fb0257c works fine - exact patch is
included - it was slightly modified to fit 2.6.27.x kernels)

Thank you very much for your help so far.

--   

  Tomas Kasparek, PhD student  E-mail: kasparek@fit.vutbr.cz
  CVT FIT VUT Brno, L127       Web:    http://www.fit.vutbr.cz/~kasparek
  Bozetechova 1, 612 66        Fax:    +420 54114-1270
  Brno, Czech Republic         Phone:  +420 54114-1220

  jabber: tomas.kasparek-2ASvDZBniIelVyrhU4qvOw@public.gmane.org
  GPG: 2F1E 1AAF FD3B CFA3 1537  63BD DCBE 18FF A035 53BC

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Kasparek Tomas]

[-- Attachment #1: Type: text/plain, Size: 2596 bytes --]

On Tue, Dec 16, 2008 at 01:05:47PM +0100, Kasparek Tomas wrote:
> On Sun, Dec 14, 2008 at 02:50:01PM -0500, Trond Myklebust wrote:
> > On Thu, 2008-12-04 at 11:23 +0100, Kasparek Tomas wrote:
> > > On Tue, Dec 02, 2008 at 01:10:07PM -0500, Trond Myklebust wrote:
> > > > On Tue, 2008-12-02 at 17:26 +0100, Kasparek Tomas wrote:
> > > > 
> > > > > Did tried. The number should be seconds and defaults to 60, These
> > > > > connections are still there after several hours. Changing it to 10 (sec)
> > > > > and same behaviour. (BTW The server did not changed in last several months)
> > > > 
> > > > Are you seeing the same behaviour with 'netstat -t'?
> > > 
> > > yes:
> > > 
> > > root@pckasparek: ~# ssh root@pcnlp1 'netstat -pan | grep WAIT' | cut -c-85
> > > tcp    0   0 147.229.12.146:989          147.229.176.14:2049 FIN_WAIT2
> > > root@pckasparek: ~# ssh root@pcnlp1 'netstat -t | grep WAIT' | cut -c-85
> > > tcp    0   0 pcnlp1.fit.vutbr.:ftps-data eva.fit.vutbr.cz:nfs FIN_WAIT2
> > > 
> > > but it should be the same, did't it? -t just selects TCP connections and
> > > this is TCP connection so it shows the same
> > 
> > Right, but the point is that the client is in the state FIN_WAIT2, which
> > means that it has closed the socket on its end, and is waiting for the
> > server to close on its end. The fact that the server is failing to do
> > this is a server bug.
> > 
> > That said, we can't wait forever for buggy servers. I see now why the
> > linger2 stuff isn't working. I believe that the appended patch should
> > help...
> 
> Hm, not happy to say that but it still does not work after some time. Now
> the problem is opposite there are no connections to the server according to
> netstat on client, just time to time there is
> 
> pcnlp1.fit.vutbr.cz.15234 > kazi.fit.vutbr.cz.nfs: 40 null
> kazi.fit.vutbr.cz.nfs > pcnlp1.fit.vutbr.cz.15234: reply ok 24 null
> 
> (kazi is server). Will try to investigate more details.
> 
> (just to remember the same kernel with reversed
> e06799f958bf7f9f8fae15f0c6f519953fb0257c works fine - exact patch is
> included - it was slightly modified to fit 2.6.27.x kernels)
> 
> Thank you very much for your help so far.

just the forgoten patch promised.

--   

  Tomas Kasparek, PhD student  E-mail: kasparek@fit.vutbr.cz
  CVT FIT VUT Brno, L127       Web:    http://www.fit.vutbr.cz/~kasparek
  Bozetechova 1, 612 66        Fax:    +420 54114-1270
  Brno, Czech Republic         Phone:  +420 54114-1220

  jabber: tomas.kasparek-2ASvDZBniIelVyrhU4qvOw@public.gmane.org
  GPG: 2F1E 1AAF FD3B CFA3 1537  63BD DCBE 18FF A035 53BC


[-- Attachment #2: linux-2.6.git-e06799f958bf7f9f8fae15f0c6f519953fb0257c-own-modified.patch --]
[-- Type: text/plain, Size: 2417 bytes --]

diff -ruN linux-2.6.27.4/net/sunrpc/xprtsock.c linux-2.6.27.4-64/net/sunrpc/xprtsock.c
--- linux-2.6.27.4/net/sunrpc/xprtsock.c	2008-11-04 14:30:26.000000000 +0100
+++ linux-2.6.27.4-64/net/sunrpc/xprtsock.c	2008-11-25 19:11:34.000000000 +0100
@@ -615,22 +615,6 @@
 	return status;
 }
 
-/**
- * xs_tcp_shutdown - gracefully shut down a TCP socket
- * @xprt: transport
- *
- * Initiates a graceful shutdown of the TCP socket by calling the
- * equivalent of shutdown(SHUT_WR);
- */
-static void xs_tcp_shutdown(struct rpc_xprt *xprt)
-{
-	struct sock_xprt *transport = container_of(xprt, struct sock_xprt, xprt);
-	struct socket *sock = transport->sock;
-
-	if (sock != NULL)
-		kernel_sock_shutdown(sock, SHUT_WR);
-}
-
 static inline void xs_encode_tcp_record_marker(struct xdr_buf *buf)
 {
 	u32 reclen = buf->len - sizeof(rpc_fraghdr);
@@ -709,7 +693,8 @@
 		dprintk("RPC:       sendmsg returned unrecognized error %d\n",
 			-status);
 		clear_bit(SOCK_ASYNC_NOSPACE, &transport->sock->flags);
-		xs_tcp_shutdown(xprt);
+ 		xprt_disconnect_done(xprt);
+        break;
 	}
 
 	return status;
@@ -1670,7 +1655,8 @@
 				break;
 			default:
 				/* get rid of existing socket, and retry */
-				xs_tcp_shutdown(xprt);
+				xs_close(xprt);
+				break;
 		}
 	}
 out:
@@ -1729,7 +1715,8 @@
 				break;
 			default:
 				/* get rid of existing socket, and retry */
-				xs_tcp_shutdown(xprt);
+				xs_close(xprt);
+				break;
 		}
 	}
 out:
@@ -1776,19 +1763,6 @@
 	}
 }
 
-static void xs_tcp_connect(struct rpc_task *task)
-{
-	struct rpc_xprt *xprt = task->tk_xprt;
-
-	/* Initiate graceful shutdown of the socket if not already done */
-	if (test_bit(XPRT_CONNECTED, &xprt->state))
-		xs_tcp_shutdown(xprt);
-	/* Exit if we need to wait for socket shutdown to complete */
-	if (test_bit(XPRT_CLOSING, &xprt->state))
-		return;
-	xs_connect(task);
-}
-
 /**
  * xs_udp_print_stats - display UDP socket-specifc stats
  * @xprt: rpc_xprt struct containing statistics
@@ -1859,12 +1833,12 @@
 	.release_xprt		= xs_tcp_release_xprt,
 	.rpcbind		= rpcb_getport_async,
 	.set_port		= xs_set_port,
-	.connect		= xs_tcp_connect,
+	.connect		= xs_connect,
 	.buf_alloc		= rpc_malloc,
 	.buf_free		= rpc_free,
 	.send_request		= xs_tcp_send_request,
 	.set_retrans_timeout	= xprt_set_retrans_timeout_def,
-	.close			= xs_tcp_shutdown,
+	.close			= xs_close,
 	.destroy		= xs_destroy,
 	.print_stats		= xs_tcp_print_stats,
 };

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Trond Myklebust]

On Tue, 2008-12-16 at 13:10 +0100, Kasparek Tomas wrote:
> On Tue, Dec 16, 2008 at 01:05:47PM +0100, Kasparek Tomas wrote:
> > On Sun, Dec 14, 2008 at 02:50:01PM -0500, Trond Myklebust wrote:
> > > On Thu, 2008-12-04 at 11:23 +0100, Kasparek Tomas wrote:
> > > > On Tue, Dec 02, 2008 at 01:10:07PM -0500, Trond Myklebust wrote:
> > > > > On Tue, 2008-12-02 at 17:26 +0100, Kasparek Tomas wrote:
> > > > > 
> > > > > > Did tried. The number should be seconds and defaults to 60, These
> > > > > > connections are still there after several hours. Changing it to 10 (sec)
> > > > > > and same behaviour. (BTW The server did not changed in last several months)
> > > > > 
> > > > > Are you seeing the same behaviour with 'netstat -t'?
> > > > 
> > > > yes:
> > > > 
> > > > root@pckasparek: ~# ssh root@pcnlp1 'netstat -pan | grep WAIT' | cut -c-85
> > > > tcp    0   0 147.229.12.146:989          147.229.176.14:2049 FIN_WAIT2
> > > > root@pckasparek: ~# ssh root@pcnlp1 'netstat -t | grep WAIT' | cut -c-85
> > > > tcp    0   0 pcnlp1.fit.vutbr.:ftps-data eva.fit.vutbr.cz:nfs FIN_WAIT2
> > > > 
> > > > but it should be the same, did't it? -t just selects TCP connections and
> > > > this is TCP connection so it shows the same
> > > 
> > > Right, but the point is that the client is in the state FIN_WAIT2, which
> > > means that it has closed the socket on its end, and is waiting for the
> > > server to close on its end. The fact that the server is failing to do
> > > this is a server bug.
> > > 
> > > That said, we can't wait forever for buggy servers. I see now why the
> > > linger2 stuff isn't working. I believe that the appended patch should
> > > help...
> > 
> > Hm, not happy to say that but it still does not work after some time. Now
> > the problem is opposite there are no connections to the server according to
> > netstat on client, just time to time there is
> > 
> > pcnlp1.fit.vutbr.cz.15234 > kazi.fit.vutbr.cz.nfs: 40 null
> > kazi.fit.vutbr.cz.nfs > pcnlp1.fit.vutbr.cz.15234: reply ok 24 null
> > 
> > (kazi is server). Will try to investigate more details.
> > 
> > (just to remember the same kernel with reversed
> > e06799f958bf7f9f8fae15f0c6f519953fb0257c works fine - exact patch is
> > included - it was slightly modified to fit 2.6.27.x kernels)
> > 
> > Thank you very much for your help so far.
> 
> just the forgoten patch promised.

NACK. That takes us right back to the previous broken behaviour.

-- 
Trond Myklebust
Linux NFS client maintainer

NetApp
Trond.Myklebust@netapp.com
www.netapp.com

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Trond Myklebust]

On Tue, 2008-12-16 at 13:05 +0100, Kasparek Tomas wrote:
> Hm, not happy to say that but it still does not work after some time. Now
> the problem is opposite there are no connections to the server according to
> netstat on client, just time to time there is
> 
> pcnlp1.fit.vutbr.cz.15234 > kazi.fit.vutbr.cz.nfs: 40 null
> kazi.fit.vutbr.cz.nfs > pcnlp1.fit.vutbr.cz.15234: reply ok 24 null
> 
> (kazi is server). Will try to investigate more details.

OK. Here is one more try. I've tightened up some locking issues with the
previous patch.

Thanks for helping test this!

Cheers
  Trond
-----------------------------------------------------------
From: Trond Myklebust <Trond.Myklebust@netapp.com>
Date: Tue, 23 Dec 2008 16:21:25 -0500
SUNRPC: Add the equivalent of the linger2 timeout to RPC sockets

This avoids us getting stuck in the TCP_FIN_WAIT2 state forever.

Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com>
---

 include/linux/sunrpc/xprt.h |    1 +
 net/sunrpc/xprtsock.c       |   63 ++++++++++++++++++++++++++++++-------------
 2 files changed, 45 insertions(+), 19 deletions(-)


diff --git a/include/linux/sunrpc/xprt.h b/include/linux/sunrpc/xprt.h
index 11fc71d..1a6ecd7 100644
--- a/include/linux/sunrpc/xprt.h
+++ b/include/linux/sunrpc/xprt.h
@@ -259,6 +259,7 @@ void			xprt_conditional_disconnect(struct rpc_xprt *xprt, unsigned int cookie);
 #define XPRT_BOUND		(4)
 #define XPRT_BINDING		(5)
 #define XPRT_CLOSING		(6)
+#define XPRT_CONNECTION_ABORT	(7)
 
 static inline void xprt_set_connected(struct rpc_xprt *xprt)
 {
diff --git a/net/sunrpc/xprtsock.c b/net/sunrpc/xprtsock.c
index 0a50361..dfb0aeb 100644
--- a/net/sunrpc/xprtsock.c
+++ b/net/sunrpc/xprtsock.c
@@ -171,6 +171,7 @@ static ctl_table sunrpc_table[] = {
  */
 #define XS_TCP_INIT_REEST_TO	(3U * HZ)
 #define XS_TCP_MAX_REEST_TO	(5U * 60 * HZ)
+#define XS_TCP_LINGER2_TO	(5U * HZ)
 
 /*
  * TCP idle timeout; client drops the transport socket if it is idle
@@ -792,6 +793,7 @@ static void xs_close(struct rpc_xprt *xprt)
 	sock_release(sock);
 clear_close_wait:
 	smp_mb__before_clear_bit();
+	clear_bit(XPRT_CONNECTION_ABORT, &xprt->state);
 	clear_bit(XPRT_CLOSE_WAIT, &xprt->state);
 	clear_bit(XPRT_CLOSING, &xprt->state);
 	smp_mb__after_clear_bit();
@@ -1126,6 +1128,7 @@ out:
  */
 static void xs_tcp_state_change(struct sock *sk)
 {
+	struct sock_xprt *transport;
 	struct rpc_xprt *xprt;
 
 	read_lock(&sk->sk_callback_lock);
@@ -1137,13 +1140,12 @@ static void xs_tcp_state_change(struct sock *sk)
 			sock_flag(sk, SOCK_DEAD),
 			sock_flag(sk, SOCK_ZAPPED));
 
+	transport = container_of(xprt, struct sock_xprt, xprt);
+
 	switch (sk->sk_state) {
 	case TCP_ESTABLISHED:
 		spin_lock_bh(&xprt->transport_lock);
 		if (!xprt_test_and_set_connected(xprt)) {
-			struct sock_xprt *transport = container_of(xprt,
-					struct sock_xprt, xprt);
-
 			/* Reset TCP record info */
 			transport->tcp_offset = 0;
 			transport->tcp_reclen = 0;
@@ -1184,7 +1186,24 @@ static void xs_tcp_state_change(struct sock *sk)
 		clear_bit(XPRT_CONNECTED, &xprt->state);
 		smp_mb__after_clear_bit();
 		break;
+	case TCP_FIN_WAIT2:
+		/* Do the equivalent of linger2 handling for dealing with
+		 * broken servers that don't close the socket in a timely
+		 * fashion
+		 */
+		if (!xprt_test_and_set_connecting(xprt)) {
+			set_bit(XPRT_CONNECTION_ABORT, &xprt->state);
+			queue_delayed_work(rpciod_workqueue,
+					&transport->connect_worker,
+					XS_TCP_LINGER2_TO);
+		}
+		break;
 	case TCP_CLOSE:
+		if (delayed_work_pending(&transport->connect_worker) &&
+			cancel_delayed_work(&transport->connect_worker)) {
+			clear_bit(XPRT_CONNECTION_ABORT, &xprt->state);
+			xprt_clear_connecting(xprt);
+		}
 		smp_mb__before_clear_bit();
 		clear_bit(XPRT_CLOSE_WAIT, &xprt->state);
 		clear_bit(XPRT_CLOSING, &xprt->state);
@@ -1549,8 +1568,8 @@ static void xs_udp_connect_worker4(struct work_struct *work)
 	xs_udp_finish_connecting(xprt, sock);
 	status = 0;
 out:
-	xprt_wake_pending_tasks(xprt, status);
 	xprt_clear_connecting(xprt);
+	xprt_wake_pending_tasks(xprt, status);
 }
 
 /**
@@ -1590,8 +1609,8 @@ static void xs_udp_connect_worker6(struct work_struct *work)
 	xs_udp_finish_connecting(xprt, sock);
 	status = 0;
 out:
-	xprt_wake_pending_tasks(xprt, status);
 	xprt_clear_connecting(xprt);
+	xprt_wake_pending_tasks(xprt, status);
 }
 
 /*
@@ -1675,6 +1694,7 @@ static void xs_tcp_connect_worker4(struct work_struct *work)
 		goto out;
 
 	if (!sock) {
+		clear_bit(XPRT_CONNECTION_ABORT, &xprt->state);
 		/* start from scratch */
 		if ((err = sock_create_kern(PF_INET, SOCK_STREAM, IPPROTO_TCP, &sock)) < 0) {
 			dprintk("RPC:       can't create TCP transport socket (%d).\n", -err);
@@ -1686,10 +1706,14 @@ static void xs_tcp_connect_worker4(struct work_struct *work)
 			sock_release(sock);
 			goto out;
 		}
-	} else
+	} else {
 		/* "close" the socket, preserving the local port */
 		xs_tcp_reuse_connection(xprt);
 
+		if (test_and_clear_bit(XPRT_CONNECTION_ABORT, &xprt->state))
+			goto out;
+	}
+
 	dprintk("RPC:       worker connecting xprt %p to address: %s\n",
 			xprt, xprt->address_strings[RPC_DISPLAY_ALL]);
 
@@ -1701,19 +1725,17 @@ static void xs_tcp_connect_worker4(struct work_struct *work)
 		switch (status) {
 			case -EINPROGRESS:
 			case -EALREADY:
-				goto out_clear;
-			case -ECONNREFUSED:
-			case -ECONNRESET:
-				/* retry with existing socket, after a delay */
 				break;
 			default:
 				/* get rid of existing socket, and retry */
 				xs_tcp_shutdown(xprt);
+			case -ECONNREFUSED:
+			case -ECONNRESET:
+				/* retry with existing socket, after a delay */
+				xprt_wake_pending_tasks(xprt, status);
 		}
 	}
 out:
-	xprt_wake_pending_tasks(xprt, status);
-out_clear:
 	xprt_clear_connecting(xprt);
 }
 
@@ -1735,6 +1757,7 @@ static void xs_tcp_connect_worker6(struct work_struct *work)
 		goto out;
 
 	if (!sock) {
+		clear_bit(XPRT_CONNECTION_ABORT, &xprt->state);
 		/* start from scratch */
 		if ((err = sock_create_kern(PF_INET6, SOCK_STREAM, IPPROTO_TCP, &sock)) < 0) {
 			dprintk("RPC:       can't create TCP transport socket (%d).\n", -err);
@@ -1746,10 +1769,14 @@ static void xs_tcp_connect_worker6(struct work_struct *work)
 			sock_release(sock);
 			goto out;
 		}
-	} else
+	} else {
 		/* "close" the socket, preserving the local port */
 		xs_tcp_reuse_connection(xprt);
 
+		if (test_and_clear_bit(XPRT_CONNECTION_ABORT, &xprt->state))
+			goto out;
+	}
+
 	dprintk("RPC:       worker connecting xprt %p to address: %s\n",
 			xprt, xprt->address_strings[RPC_DISPLAY_ALL]);
 
@@ -1760,19 +1787,17 @@ static void xs_tcp_connect_worker6(struct work_struct *work)
 		switch (status) {
 			case -EINPROGRESS:
 			case -EALREADY:
-				goto out_clear;
-			case -ECONNREFUSED:
-			case -ECONNRESET:
-				/* retry with existing socket, after a delay */
 				break;
 			default:
 				/* get rid of existing socket, and retry */
 				xs_tcp_shutdown(xprt);
+			case -ECONNREFUSED:
+			case -ECONNRESET:
+				/* retry with existing socket, after a delay */
+				xprt_wake_pending_tasks(xprt, status);
 		}
 	}
 out:
-	xprt_wake_pending_tasks(xprt, status);
-out_clear:
 	xprt_clear_connecting(xprt);
 }
 


-- 
Trond Myklebust
Linux NFS client maintainer

NetApp
Trond.Myklebust@netapp.com
www.netapp.com

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Kasparek Tomas]

On Tue, Dec 23, 2008 at 05:34:07PM -0500, Trond Myklebust wrote:
> On Tue, 2008-12-16 at 13:05 +0100, Kasparek Tomas wrote:
> > Hm, not happy to say that but it still does not work after some time. Now
> > the problem is opposite there are no connections to the server according to
> > netstat on client, just time to time there is
> > 
> > pcnlp1.fit.vutbr.cz.15234 > kazi.fit.vutbr.cz.nfs: 40 null
> > kazi.fit.vutbr.cz.nfs > pcnlp1.fit.vutbr.cz.15234: reply ok 24 null
> > 
> > (kazi is server). Will try to investigate more details.
> 
> OK. Here is one more try. I've tightened up some locking issues with the
> previous patch.
> 
> Thanks for helping test this!

Finally back from vacations, give me few days to test it. 

Thanks for your help!

--   

  Tomas Kasparek, PhD student  E-mail: kasparek@fit.vutbr.cz
  CVT FIT VUT Brno, L127       Web:    http://www.fit.vutbr.cz/~kasparek
  Bozetechova 1, 612 66        Fax:    +420 54114-1270
  Brno, Czech Republic         Phone:  +420 54114-1220

  jabber: tomas.kasparek-2ASvDZBniIelVyrhU4qvOw@public.gmane.org
  GPG: 2F1E 1AAF FD3B CFA3 1537  63BD DCBE 18FF A035 53BC

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Kasparek Tomas]

On Tue, Dec 23, 2008 at 05:34:07PM -0500, Trond Myklebust wrote:
> On Tue, 2008-12-16 at 13:05 +0100, Kasparek Tomas wrote:
> > Hm, not happy to say that but it still does not work after some time. Now
> > the problem is opposite there are no connections to the server according to
> > netstat on client, just time to time there is
> > 
> > pcnlp1.fit.vutbr.cz.15234 > kazi.fit.vutbr.cz.nfs: 40 null
> > kazi.fit.vutbr.cz.nfs > pcnlp1.fit.vutbr.cz.15234: reply ok 24 null
> > 
> > (kazi is server). Will try to investigate more details.
> 
> OK. Here is one more try. I've tightened up some locking issues with the
> previous patch.

Did tried this new version. Applied it to 2.6.27.10, but the behaviour is
the same like with the first version - when old mounts are removed by amd
new one are not created, fter a while, there are no sockets on the client
and just CLOSED sockets on server. Client is issuing null RPC checks each
30sec and they are OK, but no other communication between client and server
takes place.

15:45:41.238796 IP pcnlp1.897490 > kazi.nfs: 40 null
15:45:41.239009 IP kazi.nfs > pcnlp1.897490: reply ok 24 null


I will try to get more info, but if you have some idea where to look or
what to try, it will be helpful.

Thanks for your help

--   

  Tomas Kasparek, PhD student  E-mail: kasparek@fit.vutbr.cz
  CVT FIT VUT Brno, L127       Web:    http://www.fit.vutbr.cz/~kasparek
  Bozetechova 1, 612 66        Fax:    +420 54114-1270
  Brno, Czech Republic         Phone:  +420 54114-1220

  jabber: tomas.kasparek-2ASvDZBniIelVyrhU4qvOw@public.gmane.org
  GPG: 2F1E 1AAF FD3B CFA3 1537  63BD DCBE 18FF A035 53BC

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Trond Myklebust]

On Fri, 2009-01-09 at 15:56 +0100, Kasparek Tomas wrote:
> On Tue, Dec 23, 2008 at 05:34:07PM -0500, Trond Myklebust wrote:
> > On Tue, 2008-12-16 at 13:05 +0100, Kasparek Tomas wrote:
> > > Hm, not happy to say that but it still does not work after some time. Now
> > > the problem is opposite there are no connections to the server according to
> > > netstat on client, just time to time there is
> > > 
> > > pcnlp1.fit.vutbr.cz.15234 > kazi.fit.vutbr.cz.nfs: 40 null
> > > kazi.fit.vutbr.cz.nfs > pcnlp1.fit.vutbr.cz.15234: reply ok 24 null
> > > 
> > > (kazi is server). Will try to investigate more details.
> > 
> > OK. Here is one more try. I've tightened up some locking issues with the
> > previous patch.
> 
> Did tried this new version. Applied it to 2.6.27.10, but the behaviour is
> the same like with the first version - when old mounts are removed by amd
> new one are not created, fter a while, there are no sockets on the client
> and just CLOSED sockets on server. Client is issuing null RPC checks each
> 30sec and they are OK, but no other communication between client and server
> takes place.
> 
> 15:45:41.238796 IP pcnlp1.897490 > kazi.nfs: 40 null
> 15:45:41.239009 IP kazi.nfs > pcnlp1.897490: reply ok 24 null
> 
> 
> I will try to get more info, but if you have some idea where to look or
> what to try, it will be helpful.
> 
> Thanks for your help

Wait. You're using amd when testing? Could you please rather retry using
just a static mount? amd has historically had way too many bugs
(particularly w.r.t. tcp) to be considered a reliable test.

-- 
Trond Myklebust
Linux NFS client maintainer

NetApp
Trond.Myklebust@netapp.com
www.netapp.com

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Kasparek Tomas]

On Fri, Jan 09, 2009 at 12:59:26PM -0500, Trond Myklebust wrote:
> On Fri, 2009-01-09 at 15:56 +0100, Kasparek Tomas wrote:
> > On Tue, Dec 23, 2008 at 05:34:07PM -0500, Trond Myklebust wrote:
> > > On Tue, 2008-12-16 at 13:05 +0100, Kasparek Tomas wrote:
> > > > Hm, not happy to say that but it still does not work after some time. Now
> > > > the problem is opposite there are no connections to the server according to
> > > > netstat on client, just time to time there is
> > > > 
> > > > pcnlp1.fit.vutbr.cz.15234 > kazi.fit.vutbr.cz.nfs: 40 null
> > > > kazi.fit.vutbr.cz.nfs > pcnlp1.fit.vutbr.cz.15234: reply ok 24 null
> > > > 
> > > > (kazi is server). Will try to investigate more details.
> > > 
> > > OK. Here is one more try. I've tightened up some locking issues with the
> > > previous patch.
> > 
> > Did tried this new version. Applied it to 2.6.27.10, but the behaviour is
> > the same like with the first version - when old mounts are removed by amd
> > new one are not created, fter a while, there are no sockets on the client
> > and just CLOSED sockets on server. Client is issuing null RPC checks each
> > 30sec and they are OK, but no other communication between client and server
> > takes place.
> > 
> > 15:45:41.238796 IP pcnlp1.897490 > kazi.nfs: 40 null
> > 15:45:41.239009 IP kazi.nfs > pcnlp1.897490: reply ok 24 null
> > 
> > 
> > I will try to get more info, but if you have some idea where to look or
> > what to try, it will be helpful.
> > 
> > Thanks for your help
> 
> Wait. You're using amd when testing? Could you please rather retry using
> just a static mount? amd has historically had way too many bugs
> (particularly w.r.t. tcp) to be considered a reliable test.

Will try, but with static mount there is one stable TCP connection between
client and server so this problem can not happen at all isn't it? 

--   

  Tomas Kasparek, PhD student  E-mail: kasparek@fit.vutbr.cz
  CVT FIT VUT Brno, L127       Web:    http://www.fit.vutbr.cz/~kasparek
  Bozetechova 1, 612 66        Fax:    +420 54114-1270
  Brno, Czech Republic         Phone:  +420 54114-1220

  jabber: tomas.kasparek-2ASvDZBniIelVyrhU4qvOw@public.gmane.org
  GPG: 2F1E 1AAF FD3B CFA3 1537  63BD DCBE 18FF A035 53BC

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Trond Myklebust]

On Sat, 2009-01-10 at 11:24 +0100, Kasparek Tomas wrote:
> > Wait. You're using amd when testing? Could you please rather retry using
> > just a static mount? amd has historically had way too many bugs
> > (particularly w.r.t. tcp) to be considered a reliable test.
> 
> Will try, but with static mount there is one stable TCP connection between
> client and server so this problem can not happen at all isn't it? 

It can. The client will automatically disconnect when the mountpoint has
not used for 5 minutes.

As for amd, I know that older versions used to set absolutely insane
timeouts for tcp connections. They'd use the same defaults as UDP, IOW
timeo=7, retrans=3 ('cat /proc/mounts' should be able to tell you if
that's the case for your setup).

-- 
Trond Myklebust
Linux NFS client maintainer

NetApp
Trond.Myklebust@netapp.com
www.netapp.com

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Kasparek Tomas]

On Mon, Jan 12, 2009 at 08:17:26PM -0500, Trond Myklebust wrote:
> On Mon, 2009-01-12 at 12:40 -0500, Trond Myklebust wrote:
> > On Mon, 2009-01-12 at 10:04 +0100, Kasparek Tomas wrote:
> > > Ok, I find that allready. With static mount the behaviour is the same as
> > > with amd - no new connection is created and the client waits forever (~
> > > tens of hours at least).
> >  
> > OK. I now appear to be able to reproduce this problem. I should have a
> > fix ready soon.
> 
> The attached 2 patches have been tested using a server that was rigged
> not to ever close the socket. They appear to work fine on my setup,
> without the hang that you reported earlier.

after 8hours it seems it works both with static mount and with amd. I will
let you know the state after few more days again.

Thank you very much for your help.

--   

  Tomas Kasparek, PhD student  E-mail: kasparek@fit.vutbr.cz
  CVT FIT VUT Brno, L127       Web:    http://www.fit.vutbr.cz/~kasparek
  Bozetechova 1, 612 66        Fax:    +420 54114-1270
  Brno, Czech Republic         Phone:  +420 54114-1220

  jabber: tomas.kasparek-2ASvDZBniIelVyrhU4qvOw@public.gmane.org
  GPG: 2F1E 1AAF FD3B CFA3 1537  63BD DCBE 18FF A035 53BC

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Kasparek Tomas]

On Tue, Jan 13, 2009 at 04:22:01PM +0100, Kasparek Tomas wrote:
> On Mon, Jan 12, 2009 at 08:17:26PM -0500, Trond Myklebust wrote:
> > On Mon, 2009-01-12 at 12:40 -0500, Trond Myklebust wrote:
> > > On Mon, 2009-01-12 at 10:04 +0100, Kasparek Tomas wrote:
> > > > Ok, I find that allready. With static mount the behaviour is the same as
> > > > with amd - no new connection is created and the client waits forever (~
> > > > tens of hours at least).
> > >  
> > > OK. I now appear to be able to reproduce this problem. I should have a
> > > fix ready soon.
> > 
> > The attached 2 patches have been tested using a server that was rigged
> > not to ever close the socket. They appear to work fine on my setup,
> > without the hang that you reported earlier.
> 
> after 8hours it seems it works both with static mount and with amd. I will
> let you know the state after few more days again.
> 
> Thank you very much for your help.

Just confirming, that the last patch did help and it works well both with
static mount and amd.

Thank you very much for repairing this. Should I do something more, or can
you propagate the change into vanilla and if possible to Greg for stable to
get into 2.6.27.x ?

--   

  Tomas Kasparek, PhD student  E-mail: kasparek@fit.vutbr.cz
  CVT FIT VUT Brno, L127       Web:    http://www.fit.vutbr.cz/~kasparek
  Bozetechova 1, 612 66        Fax:    +420 54114-1270
  Brno, Czech Republic         Phone:  +420 54114-1220

  jabber: tomas.kasparek-2ASvDZBniIelVyrhU4qvOw@public.gmane.org
  GPG: 2F1E 1AAF FD3B CFA3 1537  63BD DCBE 18FF A035 53BC

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Kasparek Tomas]

On Fri, Jan 16, 2009 at 11:48:02AM +0100, Kasparek Tomas wrote:
> On Tue, Jan 13, 2009 at 04:22:01PM +0100, Kasparek Tomas wrote:
> > On Mon, Jan 12, 2009 at 08:17:26PM -0500, Trond Myklebust wrote:
> > > On Mon, 2009-01-12 at 12:40 -0500, Trond Myklebust wrote:
> > > > On Mon, 2009-01-12 at 10:04 +0100, Kasparek Tomas wrote:
> > > > > Ok, I find that allready. With static mount the behaviour is the same as
> > > > > with amd - no new connection is created and the client waits forever (~
> > > > > tens of hours at least).
> > > >  
> > > > OK. I now appear to be able to reproduce this problem. I should have a
> > > > fix ready soon.
> > > 
> > > The attached 2 patches have been tested using a server that was rigged
> > > not to ever close the socket. They appear to work fine on my setup,
> > > without the hang that you reported earlier.
> > 
> > after 8hours it seems it works both with static mount and with amd. I will
> > let you know the state after few more days again.
> > 
> > Thank you very much for your help.
> 
> Just confirming, that the last patch did help and it works well both with
> static mount and amd.
> 
> Thank you very much for repairing this. Should I do something more, or can
> you propagate the change into vanilla and if possible to Greg for stable to
> get into 2.6.27.x ?

Hi Trond, for now please do not push your patches to mainstream, I have some
big troubles with my machines and it starts loking like the new kernel may
be the cause.

It seems that machines with this new kernel (tried on 10 other machines
and the original client) may after few days get into state where they
generate huge amounts (10000-100000pkt/s) of packets on another server they
use (Linux 2.6.26.62, but the same behaviour with other kernels I tried -
2.6.24.7, 2.6.22.19, 2.6.27.10). It seems packets are quiet small as the
flow on server is about 5-10MB/s. (probably) Each packet generates an answer.
With this flow it is hard to get more info and the server is production
one, so for now I only know it goes from these clients and end on tcp port
2049 on that server. It kills just this server, communication with the
previously problematic (FreeBSD machines) is fine now.

Will try to investigate more details.

Thanks.

--   

  Tomas Kasparek, PhD student  E-mail: kasparek@fit.vutbr.cz
  CVT FIT VUT Brno, L127       Web:    http://www.fit.vutbr.cz/~kasparek
  Bozetechova 1, 612 66        Fax:    +420 54114-1270
  Brno, Czech Republic         Phone:  +420 54114-1220

  jabber: tomas.kasparek@jabber.cz
  GPG: 2F1E 1AAF FD3B CFA3 1537  63BD DCBE 18FF A035 53BC

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Kasparek Tomas]

On Sun, Jan 18, 2009 at 02:08:35PM +0100, Kasparek Tomas wrote:
> > > > The attached 2 patches have been tested using a server that was rigged
> > > > not to ever close the socket. They appear to work fine on my setup,
> > > > without the hang that you reported earlier.
> ...
> It seems that machines with this new kernel (tried on 10 other machines
> and the original client) may after few days get into state where they
> generate huge amounts (10000-100000pkt/s) of packets on another server they
> use (Linux 2.6.26.62, but the same behaviour with other kernels I tried -
> 2.6.24.7, 2.6.22.19, 2.6.27.10). It seems packets are quiet small as the
> flow on server is about 5-10MB/s. (probably) Each packet generates an answer.
> With this flow it is hard to get more info and the server is production
> one, so for now I only know it goes from these clients and end on tcp port
> 2049 on that server. It kills just this server, communication with the
> previously problematic (FreeBSD machines) is fine now.

Hi all,

configrming that the problem is with machines with 2.6.27.10+trond's
patches. Do not have more info about what's there on network, the only new
thing I can add is that the client is dead not reacting even on keyborad or
anything else. Trond, would you have and idea what to try now or what other
information to find to get any further in this?

The clients are different machines - Intel x AMD with different boards,
NICs etc. The server is dead too, but it may recover after some time - I
can not afford leaving it for longer time to see what happens.

Thanks so far.

--   

  Tomas Kasparek, PhD student  E-mail: kasparek@fit.vutbr.cz
  CVT FIT VUT Brno, L127       Web:    http://www.fit.vutbr.cz/~kasparek
  Bozetechova 1, 612 66        Fax:    +420 54114-1270
  Brno, Czech Republic         Phone:  +420 54114-1220

  jabber: tomas.kasparek-2ASvDZBniIelVyrhU4qvOw@public.gmane.org
  GPG: 2F1E 1AAF FD3B CFA3 1537  63BD DCBE 18FF A035 53BC

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Trond Myklebust]

On Tue, 2009-01-20 at 16:03 +0100, Kasparek Tomas wrote:
> On Sun, Jan 18, 2009 at 02:08:35PM +0100, Kasparek Tomas wrote:
> > > > > The attached 2 patches have been tested using a server that was rigged
> > > > > not to ever close the socket. They appear to work fine on my setup,
> > > > > without the hang that you reported earlier.
> > ...
> > It seems that machines with this new kernel (tried on 10 other machines
> > and the original client) may after few days get into state where they
> > generate huge amounts (10000-100000pkt/s) of packets on another server they
> > use (Linux 2.6.26.62, but the same behaviour with other kernels I tried -
> > 2.6.24.7, 2.6.22.19, 2.6.27.10). It seems packets are quiet small as the
> > flow on server is about 5-10MB/s. (probably) Each packet generates an answer.
> > With this flow it is hard to get more info and the server is production
> > one, so for now I only know it goes from these clients and end on tcp port
> > 2049 on that server. It kills just this server, communication with the
> > previously problematic (FreeBSD machines) is fine now.
> 
> Hi all,
> 
> configrming that the problem is with machines with 2.6.27.10+trond's
> patches. Do not have more info about what's there on network, the only new
> thing I can add is that the client is dead not reacting even on keyborad or
> anything else. Trond, would you have and idea what to try now or what other
> information to find to get any further in this?

A binary wireshark dump of the traffic between one such client and the
server would help.

Cheers
  Trond
-- 
Trond Myklebust
Linux NFS client maintainer

NetApp
Trond.Myklebust@netapp.com
www.netapp.com

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Kasparek Tomas]

On Tue, Jan 20, 2009 at 10:32:27AM -0500, Trond Myklebust wrote:
> On Tue, 2009-01-20 at 16:03 +0100, Kasparek Tomas wrote:
> > On Sun, Jan 18, 2009 at 02:08:35PM +0100, Kasparek Tomas wrote:
> > > > > > The attached 2 patches have been tested using a server that was rigged
> > > > > > not to ever close the socket. They appear to work fine on my setup,
> > > > > > without the hang that you reported earlier.
> > > ...
> > > It seems that machines with this new kernel (tried on 10 other machines
> > > and the original client) may after few days get into state where they
> > > generate huge amounts (10000-100000pkt/s) of packets on another server they
> > > use (Linux 2.6.26.62, but the same behaviour with other kernels I tried -
> > > 2.6.24.7, 2.6.22.19, 2.6.27.10). It seems packets are quiet small as the
> > > flow on server is about 5-10MB/s. (probably) Each packet generates an answer.
> > > With this flow it is hard to get more info and the server is production
> > > one, so for now I only know it goes from these clients and end on tcp port
> > > 2049 on that server. It kills just this server, communication with the
> > > previously problematic (FreeBSD machines) is fine now.
> > 
> > patches. Do not have more info about what's there on network, the only new
> > thing I can add is that the client is dead not reacting even on keyborad or
> > anything else. Trond, would you have and idea what to try now or what other
> 
> A binary wireshark dump of the traffic between one such client and the
> server would help.

I tried to get some data several times, but the client is dead and the
server is overloaded so much, that I'm unable to get anything reasonable. I
did tried to insert another mechine in front of the client as a bridge, but
the traffic overloaded it the same way as the server. I will try to figure
out how to get some traffic dump, but have no other idea for now.

Bye

--   

  Tomas Kasparek, PhD student  E-mail: kasparek@fit.vutbr.cz
  CVT FIT VUT Brno, L127       Web:    http://www.fit.vutbr.cz/~kasparek
  Bozetechova 1, 612 66        Fax:    +420 54114-1270
  Brno, Czech Republic         Phone:  +420 54114-1220

  jabber: tomas.kasparek-2ASvDZBniIelVyrhU4qvOw@public.gmane.org
  GPG: 2F1E 1AAF FD3B CFA3 1537  63BD DCBE 18FF A035 53BC

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Kasparek Tomas]

On Wed, Jan 28, 2009 at 09:18:52AM +0100, Kasparek Tomas wrote:
> On Tue, Jan 20, 2009 at 10:32:27AM -0500, Trond Myklebust wrote:
> > On Tue, 2009-01-20 at 16:03 +0100, Kasparek Tomas wrote:
> > > On Sun, Jan 18, 2009 at 02:08:35PM +0100, Kasparek Tomas wrote:
> > > > > > > The attached 2 patches have been tested using a server that was rigged
> > > > > > > not to ever close the socket. They appear to work fine on my setup,
> > > > > > > without the hang that you reported earlier.
> > > > ...
> > > > It seems that machines with this new kernel (tried on 10 other machines
> > > > and the original client) may after few days get into state where they
> > > > generate huge amounts (10000-100000pkt/s) of packets on another server they
> > > > use (Linux 2.6.26.62, but the same behaviour with other kernels I tried -
> > > > 2.6.24.7, 2.6.22.19, 2.6.27.10). It seems packets are quiet small as the
> > > > flow on server is about 5-10MB/s. (probably) Each packet generates an answer.
> > > > With this flow it is hard to get more info and the server is production
> > > > one, so for now I only know it goes from these clients and end on tcp port
> > > > 2049 on that server. It kills just this server, communication with the
> > > > previously problematic (FreeBSD machines) is fine now.
> > > 
> > > patches. Do not have more info about what's there on network, the only new
> > > thing I can add is that the client is dead not reacting even on keyborad or
> > > anything else. Trond, would you have and idea what to try now or what other
> > 
> > A binary wireshark dump of the traffic between one such client and the
> > server would help.
> 
> I tried to get some data several times, but the client is dead and the
> server is overloaded so much, that I'm unable to get anything reasonable. I
> did tried to insert another mechine in front of the client as a bridge, but
> the traffic overloaded it the same way as the server. I will try to figure
> out how to get some traffic dump, but have no other idea for now.

Hi,

as another try, I did upgrade from 2.6.27.10 to 2.6.27.13 (and .14) and it
looks like the problem disappeared. Righ now I'm running 5 clients with .13
or .14 and tcpdumps for 3 days without any problem. I will try to stop
tcpdumps as they can potentially influence behaviour and will confirm the
state next week.

Thank you very much for all the work you and others from nfs-linux are
doing!
(I'm going to test pNFS in short time, so if I can be helpfull in any
way, let me know).

Bye

--   

  Tomas Kasparek, PhD student  E-mail: kasparek@fit.vutbr.cz
  CVT FIT VUT Brno, L127       Web:    http://www.fit.vutbr.cz/~kasparek
  Bozetechova 1, 612 66        Fax:    +420 54114-1270
  Brno, Czech Republic         Phone:  +420 54114-1220

  jabber: tomas.kasparek-2ASvDZBniIelVyrhU4qvOw@public.gmane.org
  GPG: 2F1E 1AAF FD3B CFA3 1537  63BD DCBE 18FF A035 53BC

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Kasparek Tomas]

On Fri, Feb 06, 2009 at 07:35:13AM +0100, Kasparek Tomas wrote:
> > > A binary wireshark dump of the traffic between one such client and the
> > > server would help.
> > 
> > I tried to get some data several times, but the client is dead and the
> > server is overloaded so much, that I'm unable to get anything reasonable. I
> > did tried to insert another mechine in front of the client as a bridge, but
> > the traffic overloaded it the same way as the server. I will try to figure
> > out how to get some traffic dump, but have no other idea for now.

> as another try, I did upgrade from 2.6.27.10 to 2.6.27.13 (and .14) and it
> looks like the problem disappeared. Righ now I'm running 5 clients with .13
> or .14 and tcpdumps for 3 days without any problem. I will try to stop
> tcpdumps as they can potentially influence behaviour and will confirm the
> state next week.

After 6 days all machines except the first client used are fine and have no
problems. Based on this I would conclude that:

- your patch fixes the problem I had
- there may be something wrong in <2.6.27.13, but it's ok in .13+
- I finnaly have some tcpdumps from the server concerning the first
  problematic client, I will try to extract interesting packets and send it
  here if you or someone else can find anything helpfull there. With .14
  the client runs much better anyway staying alive for 3 days instead of
  6-10hours as with .10

Thank you for your support.

--   

  Tomas Kasparek, PhD student  E-mail: kasparek@fit.vutbr.cz
  CVT FIT VUT Brno, L127       Web:    http://www.fit.vutbr.cz/~kasparek
  Bozetechova 1, 612 66        Fax:    +420 54114-1270
  Brno, Czech Republic         Phone:  +420 54114-1220

  jabber: tomas.kasparek-2ASvDZBniIelVyrhU4qvOw@public.gmane.org
  GPG: 2F1E 1AAF FD3B CFA3 1537  63BD DCBE 18FF A035 53BC

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Kasparek Tomas]

On Tue, Jan 20, 2009 at 10:32:27AM -0500, Trond Myklebust wrote:
> > > > > > The attached 2 patches have been tested using a server that was rigged
> > > > > > not to ever close the socket. They appear to work fine on my setup,
> > > > > > without the hang that you reported earlier.
> > > ...
> > > It seems that machines with this new kernel (tried on 10 other machines
> > > and the original client) may after few days get into state where they
> > > generate huge amounts (10000-100000pkt/s) of packets on another server they
> > > use (Linux 2.6.26.62, but the same behaviour with other kernels I tried -
> > > 2.6.24.7, 2.6.22.19, 2.6.27.10). It seems packets are quiet small as the
> > > flow on server is about 5-10MB/s. (probably) Each packet generates an answer.
> > > With this flow it is hard to get more info and the server is production
> > > one, so for now I only know it goes from these clients and end on tcp port
> > > 2049 on that server. It kills just this server, communication with the
> > > previously problematic (FreeBSD machines) is fine now.

> > configrming that the problem is with machines with 2.6.27.10+trond's
> > patches. Do not have more info about what's there on network, the only new
> > thing I can add is that the client is dead not reacting even on keyborad or
> > anything else. Trond, would you have and idea what to try now or what other
> > information to find to get any further in this?
> 
> A binary wireshark dump of the traffic between one such client and the
> server would help.

I was able to finally got the tcpdump. I got it from 2.6.27.19 client but
after several weeks without problems. I include the file and place it on
http://merlin.fit.vutbr.cz/tmp/nfs/dump_kas2_mat.dump_small (have over 1GB
of dump, but it's all the time the same SYN+RST packets). The packet rate
maxed at 260000pps from two clients.

This dump is taken from server after reset (the server does not respond
even to keybord) before clients are disconnected/rebooted. To remind it - all
clients seems to work well with reversed
e06799f958bf7f9f8fae15f0c6f519953fb0257c

(just to be a hint do not mean the patch is wrong)

Thanks in advance

--   

  Tomas Kasparek, PhD student  E-mail: kasparek@fit.vutbr.cz
  CVT FIT VUT Brno, L127       Web:    http://www.fit.vutbr.cz/~kasparek
  Bozetechova 1, 612 66        Fax:    +420 54114-1270
  Brno, Czech Republic         Phone:  +420 54114-1220

  jabber: tomas.kasparek@jabber.cz
  GPG: 2F1E 1AAF FD3B CFA3 1537  63BD DCBE 18FF A035 53BC

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Trond Myklebust]

On Tue, 2009-03-03 at 13:08 +0100, Kasparek Tomas wrote:
> On Tue, Jan 20, 2009 at 10:32:27AM -0500, Trond Myklebust wrote:
> > A binary wireshark dump of the traffic between one such client and the
> > server would help.
> 
> I was able to finally got the tcpdump. I got it from 2.6.27.19 client but
> after several weeks without problems. I include the file and place it on
> http://merlin.fit.vutbr.cz/tmp/nfs/dump_kas2_mat.dump_small (have over 1GB
> of dump, but it's all the time the same SYN+RST packets). The packet rate
> maxed at 260000pps from two clients.
> 
> This dump is taken from server after reset (the server does not respond
> even to keybord) before clients are disconnected/rebooted. To remind it - all
> clients seems to work well with reversed
> e06799f958bf7f9f8fae15f0c6f519953fb0257c

Yes. I saw that behaviour when testing at Connectathon last week. When
one of the servers I was testing against crashed and later came up
again, the patched client went into that same SYN+RST frenzy. I'm
planning to look at this now that I'm back at home.

Cheers
  Trond

-- 
Trond Myklebust
Linux NFS client maintainer

NetApp
Trond.Myklebust@netapp.com
www.netapp.com

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Kasparek Tomas]

On Tue, Mar 03, 2009 at 09:16:07AM -0500, Trond Myklebust wrote:
> On Tue, 2009-03-03 at 13:08 +0100, Kasparek Tomas wrote:
> > On Tue, Jan 20, 2009 at 10:32:27AM -0500, Trond Myklebust wrote:
> > > A binary wireshark dump of the traffic between one such client and the
> > > server would help.
> > 
> > I was able to finally got the tcpdump. I got it from 2.6.27.19 client but
> > after several weeks without problems. I include the file and place it on
> > http://merlin.fit.vutbr.cz/tmp/nfs/dump_kas2_mat.dump_small (have over 1GB
> > of dump, but it's all the time the same SYN+RST packets). The packet rate
> > maxed at 260000pps from two clients.
> > 
> > This dump is taken from server after reset (the server does not respond
> > even to keybord) before clients are disconnected/rebooted. To remind it - all
> > clients seems to work well with reversed
> > e06799f958bf7f9f8fae15f0c6f519953fb0257c
> 
> Yes. I saw that behaviour when testing at Connectathon last week. When
> one of the servers I was testing against crashed and later came up
> again, the patched client went into that same SYN+RST frenzy. I'm
> planning to look at this now that I'm back at home.

Hi Trond, is there something new about this? Having this solved will enable
me to test 2.6.27.x on more machines and hopefully solve the last lockd
problem.

Thank you in advance

--   

  Tomas Kasparek, PhD student  E-mail: kasparek@fit.vutbr.cz
  CVT FIT VUT Brno, L127       Web:    http://www.fit.vutbr.cz/~kasparek
  Bozetechova 1, 612 66        Fax:    +420 54114-1270
  Brno, Czech Republic         Phone:  +420 54114-1220

  jabber: tomas.kasparek-2ASvDZBniIelVyrhU4qvOw@public.gmane.org
  GPG: 2F1E 1AAF FD3B CFA3 1537  63BD DCBE 18FF A035 53BC

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Kasparek Tomas]

On Tue, Mar 03, 2009 at 09:16:07AM -0500, Trond Myklebust wrote:
> On Tue, 2009-03-03 at 13:08 +0100, Kasparek Tomas wrote:
> > On Tue, Jan 20, 2009 at 10:32:27AM -0500, Trond Myklebust wrote:
> > > A binary wireshark dump of the traffic between one such client and the
> > > server would help.
> > 
> > I was able to finally got the tcpdump. I got it from 2.6.27.19 client but
> > after several weeks without problems. I include the file and place it on
> > http://merlin.fit.vutbr.cz/tmp/nfs/dump_kas2_mat.dump_small (have over 1GB
> > of dump, but it's all the time the same SYN+RST packets). The packet rate
> > maxed at 260000pps from two clients.
> > 
> > This dump is taken from server after reset (the server does not respond
> > even to keybord) before clients are disconnected/rebooted. To remind it - all
> > clients seems to work well with reversed
> > e06799f958bf7f9f8fae15f0c6f519953fb0257c
> 
> Yes. I saw that behaviour when testing at Connectathon last week. When
> one of the servers I was testing against crashed and later came up
> again, the patched client went into that same SYN+RST frenzy. I'm
> planning to look at this now that I'm back at home.

Hi, got a bit more data today as I get to the client early before it become
unresponsible. 

: BUG: soft lockup - CPU#5 stuck for 61s!  [rpciod/5:2730]
: Modules linked in: nfsd auth_rpcgss
exportfs i2c_dev i2c_core nfs lockd nfs_acl sunrpc ipv6 xfs dm_mirror 
dm_log dm_mod pci_slot fa n snd_hda_intel snd_seq_dummy thermal snd_seq_oss
snd_seq_midi_event snd_seq processor igb 8250_pnp sg firewire_ohci 
firewire_core crc_itu_t thermal_sys snd_seq_dev ice snd_pcm_oss snd_mixer_oss
evdev snd_pcm hwmon 3w_9xxx inet_lro button snd_timer sr_mod cdrom 8250
serial_core rtc_cmos rtc_core rtc_lib ehci_hcd uhci_hcd snd soundcore snd_page_alloc usbcore
: 
: Pid: 2730, comm: rpciod/5 Not tainted (2.6.27.21 #1)
: EIP: 0060:[<c02972c8>] EFLAGS: 00000202 CPU: 5
: EIP is at tcp_connect+0x213/0x2e6
: EAX: c55cf700 EBX: f67b7b40 ECX: 00000002 EDX: ed451d8c
: ESI: c5409380 EDI: 00000000 EBP: 00000001 ESP: f67cfe78
:  DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
: CR0: 8005003b CR2: b7f7b9c8 CR3: 003b5000 CR4: 000006d0
: DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
: DR6: ffff0ff0 DR7: 00000400 
:  [<c0299c5d>] ? tcp_v4_connect+0x3b2/0x40a
:  [<c02a312e>] ?  inet_stream_connect+0x87/0x20b
:  [<f8b41a88>] ?  rpc_wake_up_status+0x33/0x57 [sunrpc]
:  [<c026417a>] ? kernel_connect+0xb/0xe
:  [<f8b401b3>] ?  xs_tcp_finish_connecting+0xe4/0xea [sunrpc]
:  [<f8b41145>] ?  xs_tcp_connect_worker4+0x0/0x15a [sunrpc]
:  [<f8b41221>] ?  xs_tcp_connect_worker4+0xdc/0x15a [sunrpc]
:  [<c012854e>] ? run_workqueue+0x6a/0xe1
:  [<c0128c77>] ? worker_thread+0x0/0x8a
:  [<c0128cf6>] ? worker_thread+0x7f/0x8a
:  [<c012aeac>] ?  autoremove_wake_function+0x0/0x2b
:  [<c0128c77>] ? worker_thread+0x0/0x8a
:  [<c012ade8>] ? kthread+0x38/0x60
:  [<c012adb0>] ? kthread+0x0/0x60
:  [<c010371b>] ?  kernel_thread_helper+0x7/0x10
:  =======================

The lockup may be becouse I disconnected the cable from that client to stop
the packet storm, but still the backtrace may be usefull.

Is there anything else I can do, that will help with this problem?

Thanks in advance

--   

  Tomas Kasparek, PhD student  E-mail: kasparek@fit.vutbr.cz
  CVT FIT VUT Brno, L127       Web:    http://www.fit.vutbr.cz/~kasparek
  Bozetechova 1, 612 66        Fax:    +420 54114-1270
  Brno, Czech Republic         Phone:  +420 54114-1220

  jabber: tomas.kasparek-2ASvDZBniIelVyrhU4qvOw@public.gmane.org
  GPG: 2F1E 1AAF FD3B CFA3 1537  63BD DCBE 18FF A035 53BC

NFS client packet storm on 2.6.27.x

[Kasparek Tomas]

On Sat, Apr 18, 2009 at 07:17:39AM +0200, Kasparek Tomas wrote:
> On Tue, Mar 03, 2009 at 09:16:07AM -0500, Trond Myklebust wrote:
> > On Tue, 2009-03-03 at 13:08 +0100, Kasparek Tomas wrote:
> > > On Tue, Jan 20, 2009 at 10:32:27AM -0500, Trond Myklebust wrote:
> > > > A binary wireshark dump of the traffic between one such client and the
> > > > server would help.
> > > 
> > > I was able to finally got the tcpdump. I got it from 2.6.27.19 client but
> > > after several weeks without problems. I include the file and place it on
> > > http://merlin.fit.vutbr.cz/tmp/nfs/dump_kas2_mat.dump_small (have over 1GB
> > > of dump, but it's all the time the same SYN+RST packets). The packet rate
> > > maxed at 260000pps from two clients.
> > > 
> > > This dump is taken from server after reset (the server does not respond
> > > even to keybord) before clients are disconnected/rebooted. To remind it - all
> > > clients seems to work well with reversed
> > > e06799f958bf7f9f8fae15f0c6f519953fb0257c
> > 
> > Yes. I saw that behaviour when testing at Connectathon last week. When
> > one of the servers I was testing against crashed and later came up
> > again, the patched client went into that same SYN+RST frenzy. I'm
> > planning to look at this now that I'm back at home.
> 
> Hi, got a bit more data today as I get to the client early before it become
> unresponsible. 
> 
> 
> The lockup may be becouse I disconnected the cable from that client to stop
> the packet storm, but still the backtrace may be usefull.
> 
> Is there anything else I can do, that will help with this problem?

Hi,

(I changed the SUBJ to be more descriptive for current problem)

I got another client lockup today. It was a desktop so I have some more
dmesg warnings about soft lockup caused probably by network cable unplug
(but hopefully still showing what happens in rpciod) on

http://merlin.fit.vutbr.cz/tmp/nfs/pckas-dmesg

I can check with top, that rpciod was using 100% cpu. I limited the flow
from client to server with firewall so I was able to save the server and
get some tcpdump -s0 data (actually RPC null with ERR response from server)

Just to remind, the client is 2.6.27.21 (i386), the server is 2.6.16.62
(x86_64).

Please let me know if I can do anything more, this is really paintfull for
me.

--   

  Tomas Kasparek, PhD student  E-mail: kasparek@fit.vutbr.cz
  CVT FIT VUT Brno, L127       Web:    http://www.fit.vutbr.cz/~kasparek
  Bozetechova 1, 612 66        Fax:    +420 54114-1270
  Brno, Czech Republic         Phone:  +420 54114-1220

  jabber: tomas.kasparek-2ASvDZBniIelVyrhU4qvOw@public.gmane.org
  GPG: 2F1E 1AAF FD3B CFA3 1537  63BD DCBE 18FF A035 53BC

Re: NFS client packet storm on 2.6.27.x

[Steve Dickson]

Kasparek Tomas wrote:
> On Sat, Apr 18, 2009 at 07:17:39AM +0200, Kasparek Tomas wrote:
>> On Tue, Mar 03, 2009 at 09:16:07AM -0500, Trond Myklebust wrote:
>>> On Tue, 2009-03-03 at 13:08 +0100, Kasparek Tomas wrote:
>>>> On Tue, Jan 20, 2009 at 10:32:27AM -0500, Trond Myklebust wrote:
>>>>> A binary wireshark dump of the traffic between one such client and the
>>>>> server would help.
>>>> I was able to finally got the tcpdump. I got it from 2.6.27.19 client but
>>>> after several weeks without problems. I include the file and place it on
>>>> http://merlin.fit.vutbr.cz/tmp/nfs/dump_kas2_mat.dump_small (have over 1GB
>>>> of dump, but it's all the time the same SYN+RST packets). The packet rate
>>>> maxed at 260000pps from two clients.
>>>>
>>>> This dump is taken from server after reset (the server does not respond
>>>> even to keybord) before clients are disconnected/rebooted. To remind it - all
>>>> clients seems to work well with reversed
>>>> e06799f958bf7f9f8fae15f0c6f519953fb0257c
>>> Yes. I saw that behaviour when testing at Connectathon last week. When
>>> one of the servers I was testing against crashed and later came up
>>> again, the patched client went into that same SYN+RST frenzy. I'm
>>> planning to look at this now that I'm back at home.
>> Hi, got a bit more data today as I get to the client early before it become
>> unresponsible. 
>>
>>
>> The lockup may be becouse I disconnected the cable from that client to stop
>> the packet storm, but still the backtrace may be usefull.
>>
>> Is there anything else I can do, that will help with this problem?
> 
> Hi,
> 
> (I changed the SUBJ to be more descriptive for current problem)
> 
> I got another client lockup today. It was a desktop so I have some more
> dmesg warnings about soft lockup caused probably by network cable unplug
> (but hopefully still showing what happens in rpciod) on
> 
> http://merlin.fit.vutbr.cz/tmp/nfs/pckas-dmesg
> 
> I can check with top, that rpciod was using 100% cpu. I limited the flow
> from client to server with firewall so I was able to save the server and
> get some tcpdump -s0 data (actually RPC null with ERR response from server)
> 
> Just to remind, the client is 2.6.27.21 (i386), the server is 2.6.16.62
> (x86_64).
> 
> Please let me know if I can do anything more, this is really paintfull for
> me.
Try commenting out the tcp6/udp6 entries from /etc/netconfig....
This has help in other places...

steved.

Re: NFS client packet storm on 2.6.27.x

[Kasparek Tomas]

On Wed, Apr 29, 2009 at 08:12:38AM -0400, Steve Dickson wrote:
> > I got another client lockup today. It was a desktop so I have some more
> > dmesg warnings about soft lockup caused probably by network cable unplug
> > (but hopefully still showing what happens in rpciod) on
> > 
> > http://merlin.fit.vutbr.cz/tmp/nfs/pckas-dmesg
> > 
> > I can check with top, that rpciod was using 100% cpu. I limited the flow
> > from client to server with firewall so I was able to save the server and
> > get some tcpdump -s0 data (actually RPC null with ERR response from server)
> > 
> > Just to remind, the client is 2.6.27.21 (i386), the server is 2.6.16.62
> > (x86_64).
> > 
> > Please let me know if I can do anything more, this is really paintfull for
> > me.
> Try commenting out the tcp6/udp6 entries from /etc/netconfig....
> This has help in other places...

It's CentOS 5.3, but if you mean to disable IPv6, I can not do that, the
server is using IPv6 (but not with these clients). And as mentioned before
it works well without e06799f958bf7f9f8fae15f0c6f519953fb0257c, both for
lockd and client floods.

Bye

--   

  Tomas Kasparek, PhD student  E-mail: kasparek@fit.vutbr.cz
  CVT FIT VUT Brno, L127       Web:    http://www.fit.vutbr.cz/~kasparek
  Bozetechova 1, 612 66        Fax:    +420 54114-1270
  Brno, Czech Republic         Phone:  +420 54114-1220

  jabber: tomas.kasparek-2ASvDZBniIelVyrhU4qvOw@public.gmane.org
  GPG: 2F1E 1AAF FD3B CFA3 1537  63BD DCBE 18FF A035 53BC

Re: NFS client packet storm on 2.6.27.x

[Kasparek Tomas]

On Wed, Apr 22, 2009 at 07:27:07PM +0200, Kasparek Tomas wrote:
> I got another client lockup today. It was a desktop so I have some more
> dmesg warnings about soft lockup caused probably by network cable unplug
> (but hopefully still showing what happens in rpciod) on
> 
> http://merlin.fit.vutbr.cz/tmp/nfs/pckas-dmesg
> 
> I can check with top, that rpciod was using 100% cpu. I limited the flow
> from client to server with firewall so I was able to save the server and
> get some tcpdump -s0 data (actually RPC null with ERR response from server)
> 
> Just to remind, the client is 2.6.27.21 (i386), the server is 2.6.16.62
> (x86_64).

Hi, I was playing with patches from

http://www.linux-nfs.org/Linux-2.6.x/2.6.27/

and find, that 

.../fixups_4/linux-2.6.27-001-respond_promptly_to_socket_errors.dif
.../fixups_4/linux-2.6.27-002-respond_promptly_to_socket_errors_2.dif

change the locking behaviour from long to endless lock to 1-2sec locks and
it seems there are fewer situations when it locks.

The packet storms does not repeat once I switched to 2.6.27.24 (and .25)
kernels so far, so it may be solved by some other patch inside .24 too.

Together with tcp_linger patch it seems to improve the situation a lot to
state when it is possible for me to use 2.6.27.x kernels.

Trond, will it be possible to get tcp_linger and the upper twho patches to
2.6.27.x stable queue so others get these fixes?

Big thanks for your help to all.

--   

  Tomas Kasparek, PhD student  E-mail: kasparek@fit.vutbr.cz
  CVT FIT VUT Brno, L127       Web:    http://www.fit.vutbr.cz/~kasparek
  Bozetechova 1, 612 66        Fax:    +420 54114-1270
  Brno, Czech Republic         Phone:  +420 54114-1220

  jabber: tomas.kasparek-2ASvDZBniIelVyrhU4qvOw@public.gmane.org
  GPG: 2F1E 1AAF FD3B CFA3 1537  63BD DCBE 18FF A035 53BC

Re: NFS client packet storm on 2.6.27.x

[Kasparek Tomas]

On Thu, Jun 25, 2009 at 07:55:32AM +0200, Kasparek Tomas wrote:
> http://www.linux-nfs.org/Linux-2.6.x/2.6.27/
> 
> .../fixups_4/linux-2.6.27-001-respond_promptly_to_socket_errors.dif
> .../fixups_4/linux-2.6.27-002-respond_promptly_to_socket_errors_2.dif
> 
> ...
> Together with tcp_linger patch it seems to improve the situation a lot to
> state when it is possible for me to use 2.6.27.x kernels.
> 
> Trond, will it be possible to get tcp_linger and the upper twho patches to
> 2.6.27.x stable queue so others get these fixes?

I got no response so far, is there someone who could advise me what to do
to get above patches to 2.6.27.x stable? Or is there some reason, why this
is not possible at all?

Thanks for advice and/or suggestions.

--   

  Tomas Kasparek, PhD student  E-mail: kasparek@fit.vutbr.cz
  CVT FIT VUT Brno, L127       Web:    http://www.fit.vutbr.cz/~kasparek
  Bozetechova 1, 612 66        Fax:    +420 54114-1270
  Brno, Czech Republic         Phone:  +420 54114-1220

  jabber: tomas.kasparek-2ASvDZBniIelVyrhU4qvOw@public.gmane.org
  GPG: 2F1E 1AAF FD3B CFA3 1537  63BD DCBE 18FF A035 53BC

Re: [stable] NFS client packet storm on 2.6.27.x

[Greg KH]

On Mon, Jul 13, 2009 at 01:12:15PM +0200, Kasparek Tomas wrote:
> On Thu, Jun 25, 2009 at 07:55:32AM +0200, Kasparek Tomas wrote:
> > http://www.linux-nfs.org/Linux-2.6.x/2.6.27/
> > 
> > .../fixups_4/linux-2.6.27-001-respond_promptly_to_socket_errors.dif
> > .../fixups_4/linux-2.6.27-002-respond_promptly_to_socket_errors_2.dif
> > 
> > ...
> > Together with tcp_linger patch it seems to improve the situation a lot to
> > state when it is possible for me to use 2.6.27.x kernels.
> > 
> > Trond, will it be possible to get tcp_linger and the upper twho patches to
> > 2.6.27.x stable queue so others get these fixes?
> 
> I got no response so far, is there someone who could advise me what to do
> to get above patches to 2.6.27.x stable? Or is there some reason, why this
> is not possible at all?

Can you backport them and send them to stable@kernel.org with the git
commit ids of the orignal patches?

thanks,

greg k-h

Re: [stable] NFS client packet storm on 2.6.27.x

[Trond Myklebust]

On Mon, 2009-07-13 at 10:20 -0700, Greg KH wrote:
> On Mon, Jul 13, 2009 at 01:12:15PM +0200, Kasparek Tomas wrote:
> > On Thu, Jun 25, 2009 at 07:55:32AM +0200, Kasparek Tomas wrote:
> > > http://www.linux-nfs.org/Linux-2.6.x/2.6.27/
> > > 
> > > .../fixups_4/linux-2.6.27-001-respond_promptly_to_socket_errors.dif
> > > .../fixups_4/linux-2.6.27-002-respond_promptly_to_socket_errors_2.dif
> > > 
> > > ...
> > > Together with tcp_linger patch it seems to improve the situation a lot to
> > > state when it is possible for me to use 2.6.27.x kernels.
> > > 
> > > Trond, will it be possible to get tcp_linger and the upper twho patches to
> > > 2.6.27.x stable queue so others get these fixes?
> > 
> > I got no response so far, is there someone who could advise me what to do
> > to get above patches to 2.6.27.x stable? Or is there some reason, why this
> > is not possible at all?
> 
> Can you backport them and send them to stable@kernel.org with the git
> commit ids of the orignal patches?

When testing at a customer site, we recently found that we actually need
4 patches in order to completely fix the storming problem in 2.6.27.y,
and ensure a timely socket reconnect.

commit 15f081ca8ddfe150fb639c591b18944a539da0fc (SUNRPC: Avoid an
unnecessary task reschedule on ENOTCONN)

commit 670f94573104b4a25525d3fcdcd6496c678df172 (SUNRPC: Ensure we set
XPRT_CLOSING only after we've sent a tcp FIN...)

commit 40d2549db5f515e415894def98b49db7d4c56714 (SUNRPC: Don't
disconnect if a connection is still in progress.)

and finally

commit f75e6745aa3084124ae1434fd7629853bdaf6798 (SUNRPC: Fix the problem
of EADDRNOTAVAIL syslog floods on reconnect)

The first three need to be applied to kernels 2.6.27.y to 2.6.29.y,
while the last needs to be applied to 2.6.27.y to 2.6.30.y.

I'll ensure the patches get sent to stable@kernel.org...

   Trond

Re: [stable] NFS client packet storm on 2.6.27.x

[Kasparek Tomas]

On Mon, Jul 13, 2009 at 01:40:17PM -0400, Trond Myklebust wrote:
> > > I got no response so far, is there someone who could advise me what to do
> > > to get above patches to 2.6.27.x stable? Or is there some reason, why this
> > > is not possible at all?
> > 
> > Can you backport them and send them to stable@kernel.org with the git
> > commit ids of the orignal patches?
> 
> When testing at a customer site, we recently found that we actually need
> 4 patches in order to completely fix the storming problem in 2.6.27.y,
> and ensure a timely socket reconnect.
> 
> commit 15f081ca8ddfe150fb639c591b18944a539da0fc (SUNRPC: Avoid an
> unnecessary task reschedule on ENOTCONN)
> 
> commit 670f94573104b4a25525d3fcdcd6496c678df172 (SUNRPC: Ensure we set
> XPRT_CLOSING only after we've sent a tcp FIN...)
> 
> commit 40d2549db5f515e415894def98b49db7d4c56714 (SUNRPC: Don't
> disconnect if a connection is still in progress.)
> 
> and finally
> 
> commit f75e6745aa3084124ae1434fd7629853bdaf6798 (SUNRPC: Fix the problem
> of EADDRNOTAVAIL syslog floods on reconnect)

Hi,

I checked that patches, all except f75e67... apply only with offset, but
the last one is a bit more ticky. Do you have these patches allready
backported for 2.7.27.x? If so, can you please send then to linux-nfs or
directly to me so I can test them?

Thanks in advance

--   

  Tomas Kasparek, PhD student  E-mail: kasparek@fit.vutbr.cz
  CVT FIT VUT Brno, L127       Web:    http://www.fit.vutbr.cz/~kasparek
  Bozetechova 1, 612 66        Fax:    +420 54114-1270
  Brno, Czech Republic         Phone:  +420 54114-1220

  jabber: tomas.kasparek-2ASvDZBniIelVyrhU4qvOw@public.gmane.org
  GPG: 2F1E 1AAF FD3B CFA3 1537  63BD DCBE 18FF A035 53BC

Re: [stable] NFS client packet storm on 2.6.27.x

[Greg KH]

On Mon, Jul 13, 2009 at 01:40:17PM -0400, Trond Myklebust wrote:
> On Mon, 2009-07-13 at 10:20 -0700, Greg KH wrote:
> > On Mon, Jul 13, 2009 at 01:12:15PM +0200, Kasparek Tomas wrote:
> > > On Thu, Jun 25, 2009 at 07:55:32AM +0200, Kasparek Tomas wrote:
> > > > http://www.linux-nfs.org/Linux-2.6.x/2.6.27/
> > > > 
> > > > .../fixups_4/linux-2.6.27-001-respond_promptly_to_socket_errors.dif
> > > > .../fixups_4/linux-2.6.27-002-respond_promptly_to_socket_errors_2.dif
> > > > 
> > > > ...
> > > > Together with tcp_linger patch it seems to improve the situation a lot to
> > > > state when it is possible for me to use 2.6.27.x kernels.
> > > > 
> > > > Trond, will it be possible to get tcp_linger and the upper twho patches to
> > > > 2.6.27.x stable queue so others get these fixes?
> > > 
> > > I got no response so far, is there someone who could advise me what to do
> > > to get above patches to 2.6.27.x stable? Or is there some reason, why this
> > > is not possible at all?
> > 
> > Can you backport them and send them to stable@kernel.org with the git
> > commit ids of the orignal patches?
> 
> When testing at a customer site, we recently found that we actually need
> 4 patches in order to completely fix the storming problem in 2.6.27.y,
> and ensure a timely socket reconnect.
> 
> commit 15f081ca8ddfe150fb639c591b18944a539da0fc (SUNRPC: Avoid an
> unnecessary task reschedule on ENOTCONN)
> 
> commit 670f94573104b4a25525d3fcdcd6496c678df172 (SUNRPC: Ensure we set
> XPRT_CLOSING only after we've sent a tcp FIN...)
> 
> commit 40d2549db5f515e415894def98b49db7d4c56714 (SUNRPC: Don't
> disconnect if a connection is still in progress.)

I've now applied all of these to the .27 stable tree.

> and finally
> 
> commit f75e6745aa3084124ae1434fd7629853bdaf6798 (SUNRPC: Fix the problem
> of EADDRNOTAVAIL syslog floods on reconnect)
> 
> The first three need to be applied to kernels 2.6.27.y to 2.6.29.y,
> while the last needs to be applied to 2.6.27.y to 2.6.30.y.

The last one is in .30, so it doesn't need to go there again :)

But this last one doesn't apply at all to the .27 stable tree.  Care to
refresh it and send it to stable@kernel.org if you think it is also
needed?

thanks,

greg k-h

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Ian Campbell]

[-- Attachment #1: Type: text/plain, Size: 561 bytes --]

On Sun, 2008-11-30 at 19:17 -0500, Trond Myklebust wrote: 
> Can you see if the following 3 patches help? They're against 2.6.28-rc6,
> but afaics the problems are pretty much the same on 2.6.26.

Thanks.

The server was actually running 2.6.25.7 but the matching sources have
since been removed the backports.org so I've reproduce with 2.6.26 and
now I'll add the patches.

Ian.

-- 
Ian Campbell

It has been said that man is a rational animal.  All my life I have
been searching for evidence which could support this.
		-- Bertrand Russell

[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 197 bytes --]

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Ian Campbell]

[-- Attachment #1: Type: text/plain, Size: 1063 bytes --]

On Mon, 2008-12-01 at 22:09 +0000, Ian Campbell wrote:
> On Sun, 2008-11-30 at 19:17 -0500, Trond Myklebust wrote: 
> > Can you see if the following 3 patches help? They're against 2.6.28-rc6,
> > but afaics the problems are pretty much the same on 2.6.26.
> 
> Thanks.
> 
> The server was actually running 2.6.25.7 but the matching sources have
> since been removed the backports.org so I've reproduce with 2.6.26 and
> now I'll add the patches.

Just a small progress report. Anecdotally I thought that unpatched
2.6.26.7 was worse than 2.6.25.7, mostly because it hung twice in the ~1
day I was running it where previously it was less frequent than once per
day.

With the patched server the client ran OK for 2.5 days then mysteriously
hung, the logs show none of the normal symptoms and my wife reset it
before I got home so I've no real clue what happened but I'm inclined to
think it was unrelated for now. I'll get back to you in a week or so if
the problem hasn't reoccurred.

Ian.
-- 
Ian Campbell

It's later than you think.

[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 197 bytes --]

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Ian Campbell]

[-- Attachment #1: Type: text/plain, Size: 1440 bytes --]

On Sat, 2008-12-06 at 12:16 +0000, Ian Campbell wrote:
> On Mon, 2008-12-01 at 22:09 +0000, Ian Campbell wrote:
> > On Sun, 2008-11-30 at 19:17 -0500, Trond Myklebust wrote: 
> > > Can you see if the following 3 patches help? They're against 2.6.28-rc6,
> > > but afaics the problems are pretty much the same on 2.6.26.
> > 
> > Thanks.
> > 
> > The server was actually running 2.6.25.7 but the matching sources have
> > since been removed the backports.org so I've reproduce with 2.6.26 and
> > now I'll add the patches.
> 
> Just a small progress report. Anecdotally I thought that unpatched
> 2.6.26.7 was worse than 2.6.25.7, mostly because it hung twice in the ~1
> day I was running it where previously it was less frequent than once per
> day.
> 
> With the patched server the client ran OK for 2.5 days then mysteriously
> hung, the logs show none of the normal symptoms and my wife reset it
> before I got home so I've no real clue what happened but I'm inclined to
> think it was unrelated for now. I'll get back to you in a week or so if
> the problem hasn't reoccurred.

$ uptime 
 18:15:29 up 9 days, 22 min,  1 user,  load average: 0.74, 0.64, 0.46

This is on the problematic client, so it looks like the server side fix
has sorted it. Thanks very much Trond.

Ian.
-- 
Ian Campbell

You have only to mumble a few words in church to get married and few words
in your sleep to get divorced.

[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 197 bytes --]

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[J. Bruce Fields]

On Sun, Dec 14, 2008 at 06:24:05PM +0000, Ian Campbell wrote:
> On Sat, 2008-12-06 at 12:16 +0000, Ian Campbell wrote:
> > On Mon, 2008-12-01 at 22:09 +0000, Ian Campbell wrote:
> > > On Sun, 2008-11-30 at 19:17 -0500, Trond Myklebust wrote: 
> > > > Can you see if the following 3 patches help? They're against 2.6.28-rc6,
> > > > but afaics the problems are pretty much the same on 2.6.26.
> > > 
> > > Thanks.
> > > 
> > > The server was actually running 2.6.25.7 but the matching sources have
> > > since been removed the backports.org so I've reproduce with 2.6.26 and
> > > now I'll add the patches.
> > 
> > Just a small progress report. Anecdotally I thought that unpatched
> > 2.6.26.7 was worse than 2.6.25.7, mostly because it hung twice in the ~1
> > day I was running it where previously it was less frequent than once per
> > day.
> > 
> > With the patched server the client ran OK for 2.5 days then mysteriously
> > hung, the logs show none of the normal symptoms and my wife reset it
> > before I got home so I've no real clue what happened but I'm inclined to
> > think it was unrelated for now. I'll get back to you in a week or so if
> > the problem hasn't reoccurred.
> 
> $ uptime 
>  18:15:29 up 9 days, 22 min,  1 user,  load average: 0.74, 0.64, 0.46
> 
> This is on the problematic client, so it looks like the server side fix
> has sorted it. Thanks very much Trond.

Thanks for the testing!  So this was with the following three patches
applied on the server on top of 2.6.26?

	[PATCH 1/3] SUNRPC: Ensure the server closes sockets in a timely fashion
	[PATCH 2/3] SUNRPC: We only need to call svc_delete_xprt() once...
	[PATCH 3/3] SUNRPC: svc_xprt_enqueue should not refuse to enqueue 'XPT_DEAD' transports

I'll try to take a look at these before I leave for the holidays,
assuming the versions Trond posted on Nov. 30 are the latest.

--b.

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Ian Campbell]

[-- Attachment #1: Type: text/plain, Size: 2195 bytes --]

On Tue, 2008-12-16 at 12:55 -0500, J. Bruce Fields wrote:
> On Sun, Dec 14, 2008 at 06:24:05PM +0000, Ian Campbell wrote:
> > On Sat, 2008-12-06 at 12:16 +0000, Ian Campbell wrote:
> > > On Mon, 2008-12-01 at 22:09 +0000, Ian Campbell wrote:
> > > > On Sun, 2008-11-30 at 19:17 -0500, Trond Myklebust wrote: 
> > > > > Can you see if the following 3 patches help? They're against 2.6.28-rc6,
> > > > > but afaics the problems are pretty much the same on 2.6.26.
> > > > 
> > > > Thanks.
> > > > 
> > > > The server was actually running 2.6.25.7 but the matching sources have
> > > > since been removed the backports.org so I've reproduce with 2.6.26 and
> > > > now I'll add the patches.
> > > 
> > > Just a small progress report. Anecdotally I thought that unpatched
> > > 2.6.26.7 was worse than 2.6.25.7, mostly because it hung twice in the ~1
> > > day I was running it where previously it was less frequent than once per
> > > day.
> > > 
> > > With the patched server the client ran OK for 2.5 days then mysteriously
> > > hung, the logs show none of the normal symptoms and my wife reset it
> > > before I got home so I've no real clue what happened but I'm inclined to
> > > think it was unrelated for now. I'll get back to you in a week or so if
> > > the problem hasn't reoccurred.
> > 
> > $ uptime 
> >  18:15:29 up 9 days, 22 min,  1 user,  load average: 0.74, 0.64, 0.46
> > 
> > This is on the problematic client, so it looks like the server side fix
> > has sorted it. Thanks very much Trond.
> 
> Thanks for the testing!  So this was with the following three patches
> applied on the server on top of 2.6.26?
> 
> 	[PATCH 1/3] SUNRPC: Ensure the server closes sockets in a timely fashion
> 	[PATCH 2/3] SUNRPC: We only need to call svc_delete_xprt() once...
> 	[PATCH 3/3] SUNRPC: svc_xprt_enqueue should not refuse to enqueue 'XPT_DEAD' transports

That's right, it was actually 2.6.26.7 FWIW.

> I'll try to take a look at these before I leave for the holidays,
> assuming the versions Trond posted on Nov. 30 are the latest.

Thanks.

Ian.
-- 
Ian Campbell

The light of a hundred stars does not equal the light of the moon.

[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 197 bytes --]

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[J. Bruce Fields]

On Tue, Dec 16, 2008 at 06:39:35PM +0000, Ian Campbell wrote:
> That's right, it was actually 2.6.26.7 FWIW.
> 
> > I'll try to take a look at these before I leave for the holidays,
> > assuming the versions Trond posted on Nov. 30 are the latest.
> 
> Thanks.

Sorry for getting behind.

If you got a chance to retest with the for-2.6.29 branch at

	git://linux-nfs.org/~bfields/linux.git for-2.6.29

that'd be great; that's what I intend to send to Linus.

--b.

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[J. Bruce Fields]

On Wed, Jan 07, 2009 at 05:21:15PM -0500, J. Bruce Fields wrote:
> On Tue, Dec 16, 2008 at 06:39:35PM +0000, Ian Campbell wrote:
> > That's right, it was actually 2.6.26.7 FWIW.
> > 
> > > I'll try to take a look at these before I leave for the holidays,
> > > assuming the versions Trond posted on Nov. 30 are the latest.
> > 
> > Thanks.
> 
> Sorry for getting behind.
> 
> If you got a chance to retest with the for-2.6.29 branch at
> 
> 	git://linux-nfs.org/~bfields/linux.git for-2.6.29
> 
> that'd be great; that's what I intend to send to Linus.

(Merged now, so testing mainline as of today should work too.)

--b.

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Ian Campbell]

[-- Attachment #1: Type: text/plain, Size: 7657 bytes --]

On Thu, 2009-01-08 at 13:20 -0500, J. Bruce Fields wrote:
> On Wed, Jan 07, 2009 at 05:21:15PM -0500, J. Bruce Fields wrote:
> > On Tue, Dec 16, 2008 at 06:39:35PM +0000, Ian Campbell wrote:
> > > That's right, it was actually 2.6.26.7 FWIW.
> > > 
> > > > I'll try to take a look at these before I leave for the holidays,
> > > > assuming the versions Trond posted on Nov. 30 are the latest.
> > > 
> > > Thanks.
> > 
> > Sorry for getting behind.
> > 
> > If you got a chance to retest with the for-2.6.29 branch at
> > 
> > 	git://linux-nfs.org/~bfields/linux.git for-2.6.29
> > 
> > that'd be great; that's what I intend to send to Linus.
> 
> (Merged now, so testing mainline as of today should work too.)

The server isn't really a machine I want to test random kernels on, is
there some subset of those changesets which it would be useful for me to
pull back onto the 2.6.26 kernel I'm using to test? (I can most like
manage the backporting myself).

These two look like the relevant ones to me but I'm not sure:
22945e4a1c7454c97f5d8aee1ef526c83fef3223 svc: Clean up deferred requests on transport destruction
69b6ba3712b796a66595cfaf0a5ab4dfe1cf964a SUNRPC: Ensure the server closes sockets in a timely fashion

I think 69b6 was in the set of three I tested previously and the other
two turned into 2294?

Ian.

Full list 238c6d54830c624f34ac9cf123ac04aebfca5013..nfs-bfields/for-2.6.29:
db43910cb42285a99f45f7e0a0a32e32d0b61dcf nfsd: get rid of NFSD_VERSION
87df4de8073f922a1f643b9fa6ba0412d5529ecf nfsd: last_byte_offset
4e65ebf08951326709817e654c149d0a94982e01 nfsd: delete wrong file comment from nfsd/nfs4xdr.c
df96fcf02a5fd2ae4e9b09e079dd6ef12d10ecd7 nfsd: git rid of nfs4_cb_null_ops declaration
0407717d8587f60003f4904bff27650cd836c00c nfsd: dprint each op status in nfsd4_proc_compound
b7aeda40d3010666d2c024c80557b6aa92a1a1ad nfsd: add etoosmall to nfserrno
30fa8c0157e4591ee2227aaa0b17cd3b0da5e6cb NFSD: FIDs need to take precedence over UUIDs
24c3767e41a6a59d32bb45abe899eb194e6bf1b8 SUNRPC: The sunrpc server code should not be used by out-of-tree modules
22945e4a1c7454c97f5d8aee1ef526c83fef3223 svc: Clean up deferred requests on transport destruction
9a8d248e2d2e9c880ac4561f27fea5dc200655bd nfsd: fix double-locks of directory mutex
2779e3ae39645515cb6c1126634f47c28c9e7190 svc: Move kfree of deferral record to common code
f05ef8db1abe68e3f6fc272efee51bc54ce528c5 CRED: Fix NFSD regression
0dba7c2a9ed3d4a1e58f5d94fffa9f44dbe012e6 NLM: Clean up flow of control in make_socks() function
d3fe5ea7cf815c037c90b1f1464ffc1ab5e8601b NLM: Refactor make_socks() function
55ef1274dddd4de387c54d110e354ffbb6cdc706 nfsd: Ensure nfsv4 calls the underlying filesystem on LOCKT
69b6ba3712b796a66595cfaf0a5ab4dfe1cf964a SUNRPC: Ensure the server closes sockets in a timely fashion
262a09823bb07c6aafb6c1d312cde613d0b90c85 NFSD: Add documenting comments for nfsctl interface
9e074856caf13ba83363f73759f5e395f74ccf41 NFSD: Replace open-coded integer with macro
54224f04ae95d86b27c0673cd773ebb120d86876 NFSD: Fix a handful of coding style issues in write_filehandle()
b046ccdc1f8171f6d0129dcc2a28d49187b4bf69 NFSD: clean up failover sysctl function naming
b064ec038a6180b13e5f89b6a30b42cb5ce8febc lockd: Enable NLM use of AF_INET6
57ef692588bc225853ca3267ca5b7cea2b07e058 NLM: Rewrite IPv4 privileged requester's check
d1208f70738c91f13b4eadb1b7a694082e439da2 NLM: nlm_privileged_requester() doesn't recognize mapped loopback address
49b5699b3fc22b363534c509c1b7dba06bc677bf NSM: Move nsm_create()
b7ba597fb964dfa44284904b3b3d74d44b8e1c42 NSM: Move nsm_use_hostnames to mon.c
8529bc51d30b8f001734b29b21a51b579c260f5b NSM: Move nsm_addr() to fs/lockd/mon.c
e6765b83977f07983c7a10e6bbb19d6c7bbfc3a4 NSM: Remove include/linux/lockd/sm_inter.h
94da7663db26530a8377f7219f8be8bd4d4822c2 NSM: Replace IP address as our nlm_reboot lookup key
77a3ef33e2de6fc8aabd7cb1700bfef81757c28a NSM: More clean up of nsm_get_handle()
b39b897c259fc1fd1998505f2b1d4ec1f115bce1 NSM: Refactor nsm_handle creation into a helper function
92fd91b998a5216a6d6606704e71d541a180216c NLM: Remove "create" argument from nsm_find()
8c7378fd2a5f22016542931b887a2ae98d146eaf NLM: Call nsm_reboot_lookup() instead of nsm_find()
3420a8c4359a189f7d854ed7075d151257415447 NSM: Add nsm_lookup() function
576df4634e37e46b441fefb91915184edb13bb94 NLM: Decode "priv" argument of NLMPROC_SM_NOTIFY as an opaque
7fefc9cb9d5f129c238d93166f705c96ca2e7e51 NLM: Change nlm_host_rebooted() to take a single nlm_reboot argument
cab2d3c99165abbba2943f1b269003b17fd3b1cb NSM: Encode the new "priv" cookie for NSMPROC_MON requests
7e44d3bea21fbb9494930d1cd35ca92a9a4a3279 NSM: Generate NSMPROC_MON's "priv" argument when nsm_handle is created
05f3a9af58180d24a9decedd71d4587935782d70 NSM: Remove !nsm check from nsm_release()
bc1cc6c4e476b60df48227165990c87a22db6bb7 NSM: Remove NULL pointer check from nsm_find()
5cf1c4b19db99d21d44c2ab457cfd44eb86b4439 NSM: Add dprintk() calls in nsm_find and nsm_release
67c6d107a689243979a2b5f15244b5261634a924 NSM: Move nsm_find() to fs/lockd/mon.c
03eb1dcbb799304b58730f4dba65812f49fb305e NSM: move to xdr_stream-based XDR encoders and decoders
36e8e668d3e6a61848a8921ddeb663b417299fa5 NSM: Move NSM program and procedure numbers to fs/lockd/mon.c
9c1bfd037f7ff8badaecb47418f109148d88bf45 NSM: Move NSM-related XDR data structures to lockd's xdr.h
0c7aef4569f8680951b7dee01dddffb9d2f809ff NSM: Check result of SM_UNMON upcall
356c3eb466fd1a12afd6448d90fba3922836e5f1 NLM: Move the public declaration of nsm_unmonitor() to lockd.h
c8c23c423dec49cb439697d3dc714e1500ff1610 NSM: Release nsmhandle in nlm_destroy_host
1e49323c4ab044d05bbc68cf13cadcbd4372468c NLM: Move the public declaration of nsm_monitor() to lockd.h
5d254b119823658cc318f88589c6c426b3d0a153 NSM: Make sure to return an error if the SM_MON call result is not zero
5bc74bef7c9b652f0f2aa9c5a8d5ac86881aba79 NSM: Remove BUG_ON() in nsm_monitor()
501c1ed3fb5c2648ba1709282c71617910917f66 NLM: Remove redundant printk() in nlmclnt_lock()
9fee49024ed19d849413df4ab6ec1a1a60aaae94 NSM: Use sm_name instead of h_name in nsm_monitor() and nsm_unmonitor()
29ed1407ed81086b778ebf12145b048ac3f7e10e NSM: Support IPv6 version of mon_name
f47534f7f0ac7727e05ec4274b764b181df2cf7f NSM: Use modern style for sm_name field in nsm_handle
5acf43155d1bcc412d892c73f64044f9a826cde6 NSM: convert printk(KERN_DEBUG) to a dprintk()
a4846750f090702e2fb848ac4fe5827bcef34060 NSM: Use C99 structure initializer to initialize nsm_args
afb03699dc0a920aed3322ad0e6895533941fb1e NLM: Add helper to handle IPv4 addresses
bc995801a09d1fead0bec1356bfd836911c8eed7 NLM: Support IPv6 scope IDs in nlm_display_address()
6999fb4016b2604c2f8a65586bba4a62a4b24ce7 NLM: Remove AF_UNSPEC arm in nlm_display_address()
1df40b609ad5a622904eb652109c287fe9c93ec5 NLM: Remove address eye-catcher buffers from nlm_host
7538ce1eb656a1477bedd5b1c202226e7abf5e7b NLM: Use modern style for pointer fields in nlm_host
c72a476b4b7ecadb80185de31236edb303c1a5d0 lockd: set svc_serv->sv_maxconn to a more reasonable value (try #3)
c9233eb7b0b11ef176d4bf68da2ce85464b6ec39 sunrpc: add sv_maxconn field to svc_serv (try #3)
548eaca46b3cf4419b6c2be839a106d8641ffb70 nfsd: document new filehandle fsid types
2bd9e7b62e6e1da3f881c40c73d93e9a212ce6de nfsd: Fix leaked memory in nfs4_make_rec_clidname
9346eff0dea1e5855fba25c9fe639d92a4db3135 nfsd: Minor cleanup of find_stateid
b3d47676d474ecd914c72049c87e71e5f0ffe040 nfsd: update fh_verify description


-- 
Ian Campbell

You're definitely on their list.  The question to ask next is what list it is.

[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 197 bytes --]

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[J. Bruce Fields]

On Thu, Jan 08, 2009 at 09:22:33PM +0000, Ian Campbell wrote:
> On Thu, 2009-01-08 at 13:20 -0500, J. Bruce Fields wrote:
> > On Wed, Jan 07, 2009 at 05:21:15PM -0500, J. Bruce Fields wrote:
> > > On Tue, Dec 16, 2008 at 06:39:35PM +0000, Ian Campbell wrote:
> > > > That's right, it was actually 2.6.26.7 FWIW.
> > > > 
> > > > > I'll try to take a look at these before I leave for the holidays,
> > > > > assuming the versions Trond posted on Nov. 30 are the latest.
> > > > 
> > > > Thanks.
> > > 
> > > Sorry for getting behind.
> > > 
> > > If you got a chance to retest with the for-2.6.29 branch at
> > > 
> > > 	git://linux-nfs.org/~bfields/linux.git for-2.6.29
> > > 
> > > that'd be great; that's what I intend to send to Linus.
> > 
> > (Merged now, so testing mainline as of today should work too.)
> 
> The server isn't really a machine I want to test random kernels on, is
> there some subset of those changesets which it would be useful for me to
> pull back onto the 2.6.26 kernel I'm using to test? (I can most like
> manage the backporting myself).
> 
> These two look like the relevant ones to me but I'm not sure:
> 22945e4a1c7454c97f5d8aee1ef526c83fef3223 svc: Clean up deferred requests on transport destruction
> 69b6ba3712b796a66595cfaf0a5ab4dfe1cf964a SUNRPC: Ensure the server closes sockets in a timely fashion
> 
> I think 69b6 was in the set of three I tested previously and the other
> two turned into 2294?

Yep, exactly.--b.

> 
> Ian.
> 
> Full list 238c6d54830c624f34ac9cf123ac04aebfca5013..nfs-bfields/for-2.6.29:
> db43910cb42285a99f45f7e0a0a32e32d0b61dcf nfsd: get rid of NFSD_VERSION
> 87df4de8073f922a1f643b9fa6ba0412d5529ecf nfsd: last_byte_offset
> 4e65ebf08951326709817e654c149d0a94982e01 nfsd: delete wrong file comment from nfsd/nfs4xdr.c
> df96fcf02a5fd2ae4e9b09e079dd6ef12d10ecd7 nfsd: git rid of nfs4_cb_null_ops declaration
> 0407717d8587f60003f4904bff27650cd836c00c nfsd: dprint each op status in nfsd4_proc_compound
> b7aeda40d3010666d2c024c80557b6aa92a1a1ad nfsd: add etoosmall to nfserrno
> 30fa8c0157e4591ee2227aaa0b17cd3b0da5e6cb NFSD: FIDs need to take precedence over UUIDs
> 24c3767e41a6a59d32bb45abe899eb194e6bf1b8 SUNRPC: The sunrpc server code should not be used by out-of-tree modules
> 22945e4a1c7454c97f5d8aee1ef526c83fef3223 svc: Clean up deferred requests on transport destruction
> 9a8d248e2d2e9c880ac4561f27fea5dc200655bd nfsd: fix double-locks of directory mutex
> 2779e3ae39645515cb6c1126634f47c28c9e7190 svc: Move kfree of deferral record to common code
> f05ef8db1abe68e3f6fc272efee51bc54ce528c5 CRED: Fix NFSD regression
> 0dba7c2a9ed3d4a1e58f5d94fffa9f44dbe012e6 NLM: Clean up flow of control in make_socks() function
> d3fe5ea7cf815c037c90b1f1464ffc1ab5e8601b NLM: Refactor make_socks() function
> 55ef1274dddd4de387c54d110e354ffbb6cdc706 nfsd: Ensure nfsv4 calls the underlying filesystem on LOCKT
> 69b6ba3712b796a66595cfaf0a5ab4dfe1cf964a SUNRPC: Ensure the server closes sockets in a timely fashion
> 262a09823bb07c6aafb6c1d312cde613d0b90c85 NFSD: Add documenting comments for nfsctl interface
> 9e074856caf13ba83363f73759f5e395f74ccf41 NFSD: Replace open-coded integer with macro
> 54224f04ae95d86b27c0673cd773ebb120d86876 NFSD: Fix a handful of coding style issues in write_filehandle()
> b046ccdc1f8171f6d0129dcc2a28d49187b4bf69 NFSD: clean up failover sysctl function naming
> b064ec038a6180b13e5f89b6a30b42cb5ce8febc lockd: Enable NLM use of AF_INET6
> 57ef692588bc225853ca3267ca5b7cea2b07e058 NLM: Rewrite IPv4 privileged requester's check
> d1208f70738c91f13b4eadb1b7a694082e439da2 NLM: nlm_privileged_requester() doesn't recognize mapped loopback address
> 49b5699b3fc22b363534c509c1b7dba06bc677bf NSM: Move nsm_create()
> b7ba597fb964dfa44284904b3b3d74d44b8e1c42 NSM: Move nsm_use_hostnames to mon.c
> 8529bc51d30b8f001734b29b21a51b579c260f5b NSM: Move nsm_addr() to fs/lockd/mon.c
> e6765b83977f07983c7a10e6bbb19d6c7bbfc3a4 NSM: Remove include/linux/lockd/sm_inter.h
> 94da7663db26530a8377f7219f8be8bd4d4822c2 NSM: Replace IP address as our nlm_reboot lookup key
> 77a3ef33e2de6fc8aabd7cb1700bfef81757c28a NSM: More clean up of nsm_get_handle()
> b39b897c259fc1fd1998505f2b1d4ec1f115bce1 NSM: Refactor nsm_handle creation into a helper function
> 92fd91b998a5216a6d6606704e71d541a180216c NLM: Remove "create" argument from nsm_find()
> 8c7378fd2a5f22016542931b887a2ae98d146eaf NLM: Call nsm_reboot_lookup() instead of nsm_find()
> 3420a8c4359a189f7d854ed7075d151257415447 NSM: Add nsm_lookup() function
> 576df4634e37e46b441fefb91915184edb13bb94 NLM: Decode "priv" argument of NLMPROC_SM_NOTIFY as an opaque
> 7fefc9cb9d5f129c238d93166f705c96ca2e7e51 NLM: Change nlm_host_rebooted() to take a single nlm_reboot argument
> cab2d3c99165abbba2943f1b269003b17fd3b1cb NSM: Encode the new "priv" cookie for NSMPROC_MON requests
> 7e44d3bea21fbb9494930d1cd35ca92a9a4a3279 NSM: Generate NSMPROC_MON's "priv" argument when nsm_handle is created
> 05f3a9af58180d24a9decedd71d4587935782d70 NSM: Remove !nsm check from nsm_release()
> bc1cc6c4e476b60df48227165990c87a22db6bb7 NSM: Remove NULL pointer check from nsm_find()
> 5cf1c4b19db99d21d44c2ab457cfd44eb86b4439 NSM: Add dprintk() calls in nsm_find and nsm_release
> 67c6d107a689243979a2b5f15244b5261634a924 NSM: Move nsm_find() to fs/lockd/mon.c
> 03eb1dcbb799304b58730f4dba65812f49fb305e NSM: move to xdr_stream-based XDR encoders and decoders
> 36e8e668d3e6a61848a8921ddeb663b417299fa5 NSM: Move NSM program and procedure numbers to fs/lockd/mon.c
> 9c1bfd037f7ff8badaecb47418f109148d88bf45 NSM: Move NSM-related XDR data structures to lockd's xdr.h
> 0c7aef4569f8680951b7dee01dddffb9d2f809ff NSM: Check result of SM_UNMON upcall
> 356c3eb466fd1a12afd6448d90fba3922836e5f1 NLM: Move the public declaration of nsm_unmonitor() to lockd.h
> c8c23c423dec49cb439697d3dc714e1500ff1610 NSM: Release nsmhandle in nlm_destroy_host
> 1e49323c4ab044d05bbc68cf13cadcbd4372468c NLM: Move the public declaration of nsm_monitor() to lockd.h
> 5d254b119823658cc318f88589c6c426b3d0a153 NSM: Make sure to return an error if the SM_MON call result is not zero
> 5bc74bef7c9b652f0f2aa9c5a8d5ac86881aba79 NSM: Remove BUG_ON() in nsm_monitor()
> 501c1ed3fb5c2648ba1709282c71617910917f66 NLM: Remove redundant printk() in nlmclnt_lock()
> 9fee49024ed19d849413df4ab6ec1a1a60aaae94 NSM: Use sm_name instead of h_name in nsm_monitor() and nsm_unmonitor()
> 29ed1407ed81086b778ebf12145b048ac3f7e10e NSM: Support IPv6 version of mon_name
> f47534f7f0ac7727e05ec4274b764b181df2cf7f NSM: Use modern style for sm_name field in nsm_handle
> 5acf43155d1bcc412d892c73f64044f9a826cde6 NSM: convert printk(KERN_DEBUG) to a dprintk()
> a4846750f090702e2fb848ac4fe5827bcef34060 NSM: Use C99 structure initializer to initialize nsm_args
> afb03699dc0a920aed3322ad0e6895533941fb1e NLM: Add helper to handle IPv4 addresses
> bc995801a09d1fead0bec1356bfd836911c8eed7 NLM: Support IPv6 scope IDs in nlm_display_address()
> 6999fb4016b2604c2f8a65586bba4a62a4b24ce7 NLM: Remove AF_UNSPEC arm in nlm_display_address()
> 1df40b609ad5a622904eb652109c287fe9c93ec5 NLM: Remove address eye-catcher buffers from nlm_host
> 7538ce1eb656a1477bedd5b1c202226e7abf5e7b NLM: Use modern style for pointer fields in nlm_host
> c72a476b4b7ecadb80185de31236edb303c1a5d0 lockd: set svc_serv->sv_maxconn to a more reasonable value (try #3)
> c9233eb7b0b11ef176d4bf68da2ce85464b6ec39 sunrpc: add sv_maxconn field to svc_serv (try #3)
> 548eaca46b3cf4419b6c2be839a106d8641ffb70 nfsd: document new filehandle fsid types
> 2bd9e7b62e6e1da3f881c40c73d93e9a212ce6de nfsd: Fix leaked memory in nfs4_make_rec_clidname
> 9346eff0dea1e5855fba25c9fe639d92a4db3135 nfsd: Minor cleanup of find_stateid
> b3d47676d474ecd914c72049c87e71e5f0ffe040 nfsd: update fh_verify description
> 
> 
> -- 
> Ian Campbell
> 
> You're definitely on their list.  The question to ask next is what list it is.

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Ian Campbell]

On Thu, 2009-01-08 at 16:26 -0500, J. Bruce Fields wrote:
> On Thu, Jan 08, 2009 at 09:22:33PM +0000, Ian Campbell wrote:

> > These two look like the relevant ones to me but I'm not sure:
> > 22945e4a1c7454c97f5d8aee1ef526c83fef3223 svc: Clean up deferred requests on transport destruction
> > 69b6ba3712b796a66595cfaf0a5ab4dfe1cf964a SUNRPC: Ensure the server closes sockets in a timely fashion
> > 
> > I think 69b6 was in the set of three I tested previously and the other
> > two turned into 2294?
> 
> Yep, exactly.--b.

OK, I have patched my 2.6.26 kernel with these and it is now running.
It'll be about a week before I can say with any certainty that the issue
hasn't recurred.

Ian.
-- 
Ian Campbell
Current Noise: Pitchshifter - Subject To Status

Do I have a lifestyle yet?

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[Ian Campbell]

[-- Attachment #1: Type: text/plain, Size: 1140 bytes --]

On Thu, 2009-01-08 at 16:26 -0500, J. Bruce Fields wrote:
> 
> > > (Merged now, so testing mainline as of today should work too.)
> > 
> > The server isn't really a machine I want to test random kernels on,
> is
> > there some subset of those changesets which it would be useful for
> me to
> > pull back onto the 2.6.26 kernel I'm using to test? (I can most like
> > manage the backporting myself).
> > 
> > These two look like the relevant ones to me but I'm not sure:
> > 22945e4a1c7454c97f5d8aee1ef526c83fef3223 svc: Clean up deferred
> requests on transport destruction
> > 69b6ba3712b796a66595cfaf0a5ab4dfe1cf964a SUNRPC: Ensure the server
> closes sockets in a timely fashion
> > 
> > I think 69b6 was in the set of three I tested previously and the
> other
> > two turned into 2294?
> 
> Yep, exactly.--b.

The client machine now has an uptime of ten days without error after
these two patches were applied to the server.

Thanks everybody,
Ian.

-- 
Ian Campbell

I used to think that the brain was the most wonderful organ in
my body.  Then I realized who was telling me this.
		-- Emo Phillips

[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 197 bytes --]

Re: [PATCH 0/3] NFS regression in 2.6.26?, "task blocked for more than 120 seconds"

[J. Bruce Fields]

On Thu, Jan 22, 2009 at 08:27:40AM +0000, Ian Campbell wrote:
> On Thu, 2009-01-08 at 16:26 -0500, J. Bruce Fields wrote:
> > 
> > > > (Merged now, so testing mainline as of today should work too.)
> > > 
> > > The server isn't really a machine I want to test random kernels on,
> > is
> > > there some subset of those changesets which it would be useful for
> > me to
> > > pull back onto the 2.6.26 kernel I'm using to test? (I can most like
> > > manage the backporting myself).
> > > 
> > > These two look like the relevant ones to me but I'm not sure:
> > > 22945e4a1c7454c97f5d8aee1ef526c83fef3223 svc: Clean up deferred
> > requests on transport destruction
> > > 69b6ba3712b796a66595cfaf0a5ab4dfe1cf964a SUNRPC: Ensure the server
> > closes sockets in a timely fashion
> > > 
> > > I think 69b6 was in the set of three I tested previously and the
> > other
> > > two turned into 2294?
> > 
> > Yep, exactly.--b.
> 
> The client machine now has an uptime of ten days without error after
> these two patches were applied to the server.
> 
> Thanks everybody,

Very good, so upstream should be OK.  Thanks for the testing!

--b.

Re: [PATCH 2/3] SUNRPC: We only need to call svc_delete_xprt() once...

[Trond Myklebust]

Use XPT_DEAD to ensure that we only call xpo_detach & friends once.

Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com>
---

 net/sunrpc/svc_xprt.c |   17 +++++++++++------
 1 files changed, 11 insertions(+), 6 deletions(-)


diff --git a/net/sunrpc/svc_xprt.c b/net/sunrpc/svc_xprt.c
index bf5b5cd..a417064 100644
--- a/net/sunrpc/svc_xprt.c
+++ b/net/sunrpc/svc_xprt.c
@@ -838,6 +838,10 @@ void svc_delete_xprt(struct svc_xprt *xprt)
 {
 	struct svc_serv	*serv = xprt->xpt_server;
 
+	/* Only do this once */
+	if (test_and_set_bit(XPT_DEAD, &xprt->xpt_flags) != 0)
+		return;
+
 	dprintk("svc: svc_delete_xprt(%p)\n", xprt);
 	xprt->xpt_ops->xpo_detach(xprt);
 
@@ -851,13 +855,14 @@ void svc_delete_xprt(struct svc_xprt *xprt)
 	 * while still attached to a queue, the queue itself
 	 * is about to be destroyed (in svc_destroy).
 	 */
-	if (!test_and_set_bit(XPT_DEAD, &xprt->xpt_flags)) {
-		BUG_ON(atomic_read(&xprt->xpt_ref.refcount) < 2);
-		if (test_bit(XPT_TEMP, &xprt->xpt_flags))
-			serv->sv_tmpcnt--;
-		svc_xprt_put(xprt);
-	}
+	if (test_bit(XPT_TEMP, &xprt->xpt_flags))
+		serv->sv_tmpcnt--;
 	spin_unlock_bh(&serv->sv_lock);
+
+	/* FIXME: Is this really needed here? */
+	BUG_ON(atomic_read(&xprt->xpt_ref.refcount) < 2);
+
+	svc_xprt_put(xprt);
 }
 
 void svc_close_xprt(struct svc_xprt *xprt)

-- 
Trond Myklebust
Linux NFS client maintainer

NetApp
Trond.Myklebust@netapp.com
www.netapp.com

Re: [PATCH] NFS regression in 2.6.26?,

[Tomas Kasparek]

Ian Campbell <ijc@...> writes:

> According to bisect:
> commit e06799f958bf7f9f8fae15f0c6f519953fb0257c
> Author: Trond Myklebust <Trond.Myklebust@...>
> Date:   Mon Nov 5 15:44:12 2007 -0500
>     SUNRPC: Use shutdown() instead of close() when disconnecting a TCP 

Hi, it seems I have the same problem, with slightly different config. Client is
2.6.24.7 (OK), 2.6.25-rc1 and later (25,26,27,28-rc6) (fail). On client I get
FIN_WAIT2 state. The server is FreeBSD 7.0-STABLE (have two of them with the
same behavior). Fastest way to get into trouble is to use automounter so it
cycles the ports - when it gets to one in FIN_WAIT2 the machine gets "dead".

Reversing the patch with 2.6.27.4 seems to help, before the machine gets stuck
in ~ hour, now it is up for 16hours and seems ok.

> > That would indicate that the server is failing to close the TCP
> > connection when the client closes on its end.

Once or twice I prove with tcpdump that client send FIN, got ACK from server but
no FIN from server.

Tom