2011-05-16 18:40:42

by Harry Edmon

[permalink] [raw]
Subject: 2.6.38.6 - state manager constantly respawns

I have a NFSv4 server and client running 2.6.38.6 with Debian squeeze.
On my client kthreadd is running constantly, and my processes accounting
file is full of entries with the PPID of kthreadd and the command being
the IP number of the server with "-ma" appended, e.g.

192.168.1.12-ma

I believe this is the nfsv4 state manager being constantly being
respawned by kthreadd and quickly exiting. There are no log entries
from the state manager (or anything else from NFS). When I reboot the
system with the Debian provided 2.6.32 kernel the problem goes away.
Does anyone have an idea why this would be occurring? I have included
the kernel config file from the client.

--
Dr. Harry Edmon E-MAIL: [email protected]
206-543-0547 FAX: 206-543-0308 [email protected]
Director of IT, College of the Environment and
Director of Computing, Dept of Atmospheric Sciences
University of Washington, Box 351640, Seattle, WA 98195-1640


Attachments:
config-2.6.38.6 (54.93 kB)

2011-05-20 19:29:09

by Harry Edmon

[permalink] [raw]
Subject: Re: 2.6.38.6 - state manager constantly respawns

On 05/20/11 10:52, Trond Myklebust wrote:
> On Fri, 2011-05-20 at 13:26 -0400, Dr. J. Bruce Fields wrote:
>
>> On Fri, May 20, 2011 at 09:20:47AM -0700, Harry Edmon wrote:
>>
>>> On 05/16/11 13:53, Dr. J. Bruce Fields wrote:
>>>
>>>> Hm, so the renews all have clid 465ccc4d09000000, and the reads all have
>>>> a stateid (0, 465ccc4dc24c0a0000000000).
>>>>
>>>> So the first 4 bytes matching just tells me both were handed out by the
>>>> same server instance (so there was no server reboot in between); there's
>>>> no way for me to tell whether they really belong to the same client.
>>>>
>>>> The server does assume that any stateid from the current server instance
>>>> that no longer exists in its table is expired. I believe that's
>>>> correct, given a correctly functioning client, but perhaps I'm missing a
>>>> case.
>>>>
>>>> --b.
>>>>
>>> I am very appreciative of the quick initial comments I receive from
>>> all of you on my NFS problem. I notice that there has been silence
>>> on the problem since the 16th, so I assume that either this is a
>>> hard bug to track down or you have been busy with higher priority
>>> tasks. Is there anything I can do to help develop a solution to
>>> this problem?
>>>
>> Well, the only candidate explanation for the problem is that my
>> assumption--that any time the server gets a stateid from the current
>> boot instance that it doesn't recognize as an active stateid, it is safe
>> for the server to return EXPIRED--is wrong.
>>
>> I don't immediately see why it's wrong, and based on the silence nobody
>> else does either, but I'm not 100% convinced I'm right either.
>>
>> So one approach might be to add server code that makes a better effort
>> to return EXPIRED only when we're sure it's a stateid from an expired
>> client, and see if that solves your problem.
>>
>> Remind me, did you have an easy way to reproduce your problem?
>>
> My silence is simply because I'm mystified as to how this can happen.
> Patching for it is trivial (see below).
>
> When the server tells us that our lease is expired, the normal behaviour
> for the client is to re-establish the lease, and then proceed to recover
> all known stateids. I don't see how we can 'miss' a stateid that then
> needs to be recovered afterwards...
>
> Cheers
> Trond
>
> 8<----------------------------------------------------------------------------
> From 920ddb153f28717be363f6e87dde24ef2a8d0ce2 Mon Sep 17 00:00:00 2001
> From: Trond Myklebust<[email protected]>
> Date: Fri, 20 May 2011 13:44:02 -0400
> Subject: [PATCH] NFSv4: Handle expired stateids when the lease is still valid
>
> Currently, if the server returns NFS4ERR_EXPIRED in reply to a READ or
> WRITE, but the RENEW test determines that the lease is still active, we
> fail to recover and end up looping forever in a READ/WRITE + RENEW death
> spiral.
>
> Signed-off-by: Trond Myklebust<[email protected]>
> ---
> fs/nfs/nfs4proc.c | 9 +++++++--
> 1 files changed, 7 insertions(+), 2 deletions(-)
>
> diff --git a/fs/nfs/nfs4proc.c b/fs/nfs/nfs4proc.c
> index cf1b339..d0e15db 100644
> --- a/fs/nfs/nfs4proc.c
> +++ b/fs/nfs/nfs4proc.c
> @@ -267,9 +267,11 @@ static int nfs4_handle_exception(struct nfs_server *server, int errorcode, struc
> break;
> nfs4_schedule_stateid_recovery(server, state);
> goto wait_on_recovery;
> + case -NFS4ERR_EXPIRED:
> + if (state != NULL)
> + nfs4_schedule_stateid_recovery(server, state);
> case -NFS4ERR_STALE_STATEID:
> case -NFS4ERR_STALE_CLIENTID:
> - case -NFS4ERR_EXPIRED:
> nfs4_schedule_lease_recovery(clp);
> goto wait_on_recovery;
> #if defined(CONFIG_NFS_V4_1)
> @@ -3670,9 +3672,11 @@ nfs4_async_handle_error(struct rpc_task *task, const struct nfs_server *server,
> break;
> nfs4_schedule_stateid_recovery(server, state);
> goto wait_on_recovery;
> + case -NFS4ERR_EXPIRED:
> + if (state != NULL)
> + nfs4_schedule_stateid_recovery(server, state);
> case -NFS4ERR_STALE_STATEID:
> case -NFS4ERR_STALE_CLIENTID:
> - case -NFS4ERR_EXPIRED:
> nfs4_schedule_lease_recovery(clp);
> goto wait_on_recovery;
> #if defined(CONFIG_NFS_V4_1)
> @@ -4543,6 +4547,7 @@ int nfs4_lock_delegation_recall(struct nfs4_state *state, struct file_lock *fl)
> case -ESTALE:
> goto out;
> case -NFS4ERR_EXPIRED:
> + nfs4_schedule_stateid_recovery(server, state);
> case -NFS4ERR_STALE_CLIENTID:
> case -NFS4ERR_STALE_STATEID:
> nfs4_schedule_lease_recovery(server->nfs_client);
>
I installed this patch on my client, and now I am seeing the state
manager appear in the process accounting file about once a minute rather
that the constant respawning I saw earlier. Is once a minute normal, or
is there still a problem?

--
Dr. Harry Edmon E-MAIL: [email protected]
206-543-0547 FAX: 206-543-0308 [email protected]
Director of IT, College of the Environment and
Director of Computing, Dept of Atmospheric Sciences
University of Washington, Box 351640, Seattle, WA 98195-1640


2011-05-20 18:35:49

by Harry Edmon

[permalink] [raw]
Subject: Re: 2.6.38.6 - state manager constantly respawns

On 05/20/11 10:26, Dr. J. Bruce Fields wrote:
> On Fri, May 20, 2011 at 09:20:47AM -0700, Harry Edmon wrote:
>
>> On 05/16/11 13:53, Dr. J. Bruce Fields wrote:
>>
>>> Hm, so the renews all have clid 465ccc4d09000000, and the reads all have
>>> a stateid (0, 465ccc4dc24c0a0000000000).
>>>
>>> So the first 4 bytes matching just tells me both were handed out by the
>>> same server instance (so there was no server reboot in between); there's
>>> no way for me to tell whether they really belong to the same client.
>>>
>>> The server does assume that any stateid from the current server instance
>>> that no longer exists in its table is expired. I believe that's
>>> correct, given a correctly functioning client, but perhaps I'm missing a
>>> case.
>>>
>>> --b.
>>>
>> I am very appreciative of the quick initial comments I receive from
>> all of you on my NFS problem. I notice that there has been silence
>> on the problem since the 16th, so I assume that either this is a
>> hard bug to track down or you have been busy with higher priority
>> tasks. Is there anything I can do to help develop a solution to
>> this problem?
>>
> Well, the only candidate explanation for the problem is that my
> assumption--that any time the server gets a stateid from the current
> boot instance that it doesn't recognize as an active stateid, it is safe
> for the server to return EXPIRED--is wrong.
>
> I don't immediately see why it's wrong, and based on the silence nobody
> else does either, but I'm not 100% convinced I'm right either.
>
> So one approach might be to add server code that makes a better effort
> to return EXPIRED only when we're sure it's a stateid from an expired
> client, and see if that solves your problem.
>
> Remind me, did you have an easy way to reproduce your problem?
>
> --b.
>
It is somewhat random. Sometimes it gets better after a client
reboot. The current case I have given you does not get better with a
client reboot.

--
Dr. Harry Edmon E-MAIL: [email protected]
206-543-0547 FAX: 206-543-0308 [email protected]
Director of IT, College of the Environment and
Director of Computing, Dept of Atmospheric Sciences
University of Washington, Box 351640, Seattle, WA 98195-1640


2011-05-16 19:36:25

by Harry Edmon

[permalink] [raw]
Subject: Re: 2.6.38.6 - state manager constantly respawns


On 05/16/11 12:22, Chuck Lever wrote:
> On May 16, 2011, at 3:12 PM, Harry Edmon wrote:
>
>
>> Attached is 1000 lines of output from tshark when the problem is occurring. The client and server are connected by a private ethernet.
>>
> Disappointing: tshark is not telling us the return codes. However, I see "PUTFH;READ" then "RENEW" in a loop, which indicates the state manager thread is being kicked off because of ongoing difficulties with state recovery. Is there a stuck application on that client?
>
> Try again with "tshark -V".
>
Here is the output from tshark -V (first 50,000 lines). Nothing
appears to be stuck, and as I said when I reboot the client into 2.6.32
the problem goes away, only to reappear when I reboot it back into 2.6.38.6.

--
Dr. Harry Edmon E-MAIL: [email protected]
206-543-0547 FAX: 206-543-0308 [email protected]
Director of IT, College of the Environment and
Director of Computing, Dept of Atmospheric Sciences
University of Washington, Box 351640, Seattle, WA 98195-1640


Attachments:
capture_50000.out.gz (59.38 kB)

2011-05-20 20:23:54

by Harry Edmon

[permalink] [raw]
Subject: Re: 2.6.38.6 - state manager constantly respawns

On 05/20/11 13:11, Trond Myklebust wrote:
> On Fri, 2011-05-20 at 12:44 -0700, Harry Edmon wrote:
>
>>> Once a minute is rather unusual... What kind of server are you running
>>> against?
>>>
>>> If it is a Linux server, what is the value contained in the virtual file
>>> "/proc/fs/nfsd/nfsv4leasetime" ?
>>>
>>>
>>>
>> Same as before - Debian Squeeze running 2.6.38.6. The value of
>> /proc/fs/nfsd/nfsv4leasetime is 90 and is not something I changed.
>>
> OK... Does 'nfsstat' on the server show any 'delegreturn' updates around
> the time when the state manager thread runs? It could just be that it is
> reaping all your unused delegations.
>
>
That number seems to be increasing all the time, whether or not the
state manager process appears in the accounting file. And this is only
the one NFS client for this sever.

--
Dr. Harry Edmon E-MAIL: [email protected]
206-543-0547 FAX: 206-543-0308 [email protected]
Director of IT, College of the Environment and
Director of Computing, Dept of Atmospheric Sciences
University of Washington, Box 351640, Seattle, WA 98195-1640


2011-05-16 19:43:40

by Myklebust, Trond

[permalink] [raw]
Subject: Re: 2.6.38.6 - state manager constantly respawns

On Mon, 2011-05-16 at 12:36 -0700, Harry Edmon wrote:
> On 05/16/11 12:22, Chuck Lever wrote:
> > On May 16, 2011, at 3:12 PM, Harry Edmon wrote:
> >
> >
> >> Attached is 1000 lines of output from tshark when the problem is occurring. The client and server are connected by a private ethernet.
> >>
> > Disappointing: tshark is not telling us the return codes. However, I see "PUTFH;READ" then "RENEW" in a loop, which indicates the state manager thread is being kicked off because of ongoing difficulties with state recovery. Is there a stuck application on that client?
> >
> > Try again with "tshark -V".
> >
> Here is the output from tshark -V (first 50,000 lines). Nothing
> appears to be stuck, and as I said when I reboot the client into 2.6.32
> the problem goes away, only to reappear when I reboot it back into 2.6.38.6.
>

Possibly, but it definitely indicates a server bug. What kind of server
are you using?

Basically, the client is getting confused because when it sends a READ,
the server is telling it that the lease has expired, then when it sends
a RENEW, the same server replies that the lease is OK...

Trond
--
Trond Myklebust
Linux NFS client maintainer

NetApp
[email protected]
http://www.netapp.com


2011-05-20 19:32:15

by J. Bruce Fields

[permalink] [raw]
Subject: Re: 2.6.38.6 - state manager constantly respawns

On Fri, May 20, 2011 at 03:15:33PM -0400, Trond Myklebust wrote:
> On Fri, 2011-05-20 at 14:59 -0400, Dr. J. Bruce Fields wrote:
> > > Bruce,
> > >
> > > If the clientid expired, is it possible that the server may have handed
> > > out the same numerical short clientid to someone else and that explains
> > > why the RENEW is succeeding?
> >
> > Clientid's are created from a u32 counter that's sampled only under the
> > state lock, so it sounds unlikely.
> >
> > I think more likely would be some bug affecting the lifetime of a
> > stateid--e.g. if the server destroyed a lock stateid earlier than it
> > should in some case, then this would happen. (Since, as I say, we
> > assume EXPIRED for any stateid we don't recognize.)
>
> Shouldn't that be a NFS4ERR_BAD_STATEID instead of NFS4ERR_EXPIRED?

Probably so, but absent a bug on either side I can't see a case where it
would make a difference; can you?

--b.

> The
> latter should really be reserved for the case where you know that this
> stateid came from an expired lease.

2011-05-20 20:11:39

by Myklebust, Trond

[permalink] [raw]
Subject: Re: 2.6.38.6 - state manager constantly respawns

On Fri, 2011-05-20 at 12:44 -0700, Harry Edmon wrote:
> > Once a minute is rather unusual... What kind of server are you running
> > against?
> >
> > If it is a Linux server, what is the value contained in the virtual file
> > "/proc/fs/nfsd/nfsv4leasetime" ?
> >
> >
> Same as before - Debian Squeeze running 2.6.38.6. The value of
> /proc/fs/nfsd/nfsv4leasetime is 90 and is not something I changed.

OK... Does 'nfsstat' on the server show any 'delegreturn' updates around
the time when the state manager thread runs? It could just be that it is
reaping all your unused delegations.

--
Trond Myklebust
Linux NFS client maintainer

NetApp
[email protected]
http://www.netapp.com


2011-05-20 18:47:41

by J. Bruce Fields

[permalink] [raw]
Subject: Re: 2.6.38.6 - state manager constantly respawns

On Fri, May 20, 2011 at 01:52:43PM -0400, Trond Myklebust wrote:
> On Fri, 2011-05-20 at 13:26 -0400, Dr. J. Bruce Fields wrote:
> > On Fri, May 20, 2011 at 09:20:47AM -0700, Harry Edmon wrote:
> > > On 05/16/11 13:53, Dr. J. Bruce Fields wrote:
> > > >Hm, so the renews all have clid 465ccc4d09000000, and the reads all have
> > > >a stateid (0, 465ccc4dc24c0a0000000000).
> > > >
> > > >So the first 4 bytes matching just tells me both were handed out by the
> > > >same server instance (so there was no server reboot in between); there's
> > > >no way for me to tell whether they really belong to the same client.
> > > >
> > > >The server does assume that any stateid from the current server instance
> > > >that no longer exists in its table is expired. I believe that's
> > > >correct, given a correctly functioning client, but perhaps I'm missing a
> > > >case.
> > > >
> > > >--b.
> > > I am very appreciative of the quick initial comments I receive from
> > > all of you on my NFS problem. I notice that there has been silence
> > > on the problem since the 16th, so I assume that either this is a
> > > hard bug to track down or you have been busy with higher priority
> > > tasks. Is there anything I can do to help develop a solution to
> > > this problem?
> >
> > Well, the only candidate explanation for the problem is that my
> > assumption--that any time the server gets a stateid from the current
> > boot instance that it doesn't recognize as an active stateid, it is safe
> > for the server to return EXPIRED--is wrong.
> >
> > I don't immediately see why it's wrong, and based on the silence nobody
> > else does either, but I'm not 100% convinced I'm right either.
> >
> > So one approach might be to add server code that makes a better effort
> > to return EXPIRED only when we're sure it's a stateid from an expired
> > client, and see if that solves your problem.
> >
> > Remind me, did you have an easy way to reproduce your problem?
>
> My silence is simply because I'm mystified as to how this can happen.

So since the client's sending it with a READ, the client thinks that the
stateid is still a valid open, lock, or delegation stateid, while the
server thinks it's not. Hm.

--b.

> Patching for it is trivial (see below).
>
> When the server tells us that our lease is expired, the normal behaviour
> for the client is to re-establish the lease, and then proceed to recover
> all known stateids. I don't see how we can 'miss' a stateid that then
> needs to be recovered afterwards...

2011-05-20 19:44:38

by Harry Edmon

[permalink] [raw]
Subject: Re: 2.6.38.6 - state manager constantly respawns

On 05/20/11 12:40, Trond Myklebust wrote:
> On Fri, 2011-05-20 at 12:29 -0700, Harry Edmon wrote:
>
>> On 05/20/11 10:52, Trond Myklebust wrote:
>>
>>> On Fri, 2011-05-20 at 13:26 -0400, Dr. J. Bruce Fields wrote:
>>>
>>>
>>>> On Fri, May 20, 2011 at 09:20:47AM -0700, Harry Edmon wrote:
>>>>
>>>>
>>>>> On 05/16/11 13:53, Dr. J. Bruce Fields wrote:
>>>>>
>>>>>
>>>>>> Hm, so the renews all have clid 465ccc4d09000000, and the reads all have
>>>>>> a stateid (0, 465ccc4dc24c0a0000000000).
>>>>>>
>>>>>> So the first 4 bytes matching just tells me both were handed out by the
>>>>>> same server instance (so there was no server reboot in between); there's
>>>>>> no way for me to tell whether they really belong to the same client.
>>>>>>
>>>>>> The server does assume that any stateid from the current server instance
>>>>>> that no longer exists in its table is expired. I believe that's
>>>>>> correct, given a correctly functioning client, but perhaps I'm missing a
>>>>>> case.
>>>>>>
>>>>>> --b.
>>>>>>
>>>>>>
>>>>> I am very appreciative of the quick initial comments I receive from
>>>>> all of you on my NFS problem. I notice that there has been silence
>>>>> on the problem since the 16th, so I assume that either this is a
>>>>> hard bug to track down or you have been busy with higher priority
>>>>> tasks. Is there anything I can do to help develop a solution to
>>>>> this problem?
>>>>>
>>>>>
>>>> Well, the only candidate explanation for the problem is that my
>>>> assumption--that any time the server gets a stateid from the current
>>>> boot instance that it doesn't recognize as an active stateid, it is safe
>>>> for the server to return EXPIRED--is wrong.
>>>>
>>>> I don't immediately see why it's wrong, and based on the silence nobody
>>>> else does either, but I'm not 100% convinced I'm right either.
>>>>
>>>> So one approach might be to add server code that makes a better effort
>>>> to return EXPIRED only when we're sure it's a stateid from an expired
>>>> client, and see if that solves your problem.
>>>>
>>>> Remind me, did you have an easy way to reproduce your problem?
>>>>
>>>>
>>> My silence is simply because I'm mystified as to how this can happen.
>>> Patching for it is trivial (see below).
>>>
>>> When the server tells us that our lease is expired, the normal behaviour
>>> for the client is to re-establish the lease, and then proceed to recover
>>> all known stateids. I don't see how we can 'miss' a stateid that then
>>> needs to be recovered afterwards...
>>>
>>> Cheers
>>> Trond
>>>
>>> 8<----------------------------------------------------------------------------
>>> From 920ddb153f28717be363f6e87dde24ef2a8d0ce2 Mon Sep 17 00:00:00 2001
>>> From: Trond Myklebust<[email protected]>
>>> Date: Fri, 20 May 2011 13:44:02 -0400
>>> Subject: [PATCH] NFSv4: Handle expired stateids when the lease is still valid
>>>
>>> Currently, if the server returns NFS4ERR_EXPIRED in reply to a READ or
>>> WRITE, but the RENEW test determines that the lease is still active, we
>>> fail to recover and end up looping forever in a READ/WRITE + RENEW death
>>> spiral.
>>>
>>> Signed-off-by: Trond Myklebust<[email protected]>
>>> ---
>>> fs/nfs/nfs4proc.c | 9 +++++++--
>>> 1 files changed, 7 insertions(+), 2 deletions(-)
>>>
>>> diff --git a/fs/nfs/nfs4proc.c b/fs/nfs/nfs4proc.c
>>> index cf1b339..d0e15db 100644
>>> --- a/fs/nfs/nfs4proc.c
>>> +++ b/fs/nfs/nfs4proc.c
>>> @@ -267,9 +267,11 @@ static int nfs4_handle_exception(struct nfs_server *server, int errorcode, struc
>>> break;
>>> nfs4_schedule_stateid_recovery(server, state);
>>> goto wait_on_recovery;
>>> + case -NFS4ERR_EXPIRED:
>>> + if (state != NULL)
>>> + nfs4_schedule_stateid_recovery(server, state);
>>> case -NFS4ERR_STALE_STATEID:
>>> case -NFS4ERR_STALE_CLIENTID:
>>> - case -NFS4ERR_EXPIRED:
>>> nfs4_schedule_lease_recovery(clp);
>>> goto wait_on_recovery;
>>> #if defined(CONFIG_NFS_V4_1)
>>> @@ -3670,9 +3672,11 @@ nfs4_async_handle_error(struct rpc_task *task, const struct nfs_server *server,
>>> break;
>>> nfs4_schedule_stateid_recovery(server, state);
>>> goto wait_on_recovery;
>>> + case -NFS4ERR_EXPIRED:
>>> + if (state != NULL)
>>> + nfs4_schedule_stateid_recovery(server, state);
>>> case -NFS4ERR_STALE_STATEID:
>>> case -NFS4ERR_STALE_CLIENTID:
>>> - case -NFS4ERR_EXPIRED:
>>> nfs4_schedule_lease_recovery(clp);
>>> goto wait_on_recovery;
>>> #if defined(CONFIG_NFS_V4_1)
>>> @@ -4543,6 +4547,7 @@ int nfs4_lock_delegation_recall(struct nfs4_state *state, struct file_lock *fl)
>>> case -ESTALE:
>>> goto out;
>>> case -NFS4ERR_EXPIRED:
>>> + nfs4_schedule_stateid_recovery(server, state);
>>> case -NFS4ERR_STALE_CLIENTID:
>>> case -NFS4ERR_STALE_STATEID:
>>> nfs4_schedule_lease_recovery(server->nfs_client);
>>>
>>>
>> I installed this patch on my client, and now I am seeing the state
>> manager appear in the process accounting file about once a minute rather
>> that the constant respawning I saw earlier. Is once a minute normal, or
>> is there still a problem?
>>
> Once a minute is rather unusual... What kind of server are you running
> against?
>
> If it is a Linux server, what is the value contained in the virtual file
> "/proc/fs/nfsd/nfsv4leasetime" ?
>
>
Same as before - Debian Squeeze running 2.6.38.6. The value of
/proc/fs/nfsd/nfsv4leasetime is 90 and is not something I changed.

--
Dr. Harry Edmon E-MAIL: [email protected]
206-543-0547 FAX: 206-543-0308 [email protected]
Director of IT, College of the Environment and
Director of Computing, Dept of Atmospheric Sciences
University of Washington, Box 351640, Seattle, WA 98195-1640


2011-05-20 18:50:57

by Anna Schumaker

[permalink] [raw]
Subject: Re: 2.6.38.6 - state manager constantly respawns

On 05/20/2011 02:47 PM, Dr. J. Bruce Fields wrote:
> On Fri, May 20, 2011 at 01:52:43PM -0400, Trond Myklebust wrote:
>> On Fri, 2011-05-20 at 13:26 -0400, Dr. J. Bruce Fields wrote:
>>> On Fri, May 20, 2011 at 09:20:47AM -0700, Harry Edmon wrote:
>>>> On 05/16/11 13:53, Dr. J. Bruce Fields wrote:
>>>>> Hm, so the renews all have clid 465ccc4d09000000, and the reads all have
>>>>> a stateid (0, 465ccc4dc24c0a0000000000).
>>>>>
>>>>> So the first 4 bytes matching just tells me both were handed out by the
>>>>> same server instance (so there was no server reboot in between); there's
>>>>> no way for me to tell whether they really belong to the same client.
>>>>>
>>>>> The server does assume that any stateid from the current server instance
>>>>> that no longer exists in its table is expired. I believe that's
>>>>> correct, given a correctly functioning client, but perhaps I'm missing a
>>>>> case.
>>>>>
>>>>> --b.
>>>> I am very appreciative of the quick initial comments I receive from
>>>> all of you on my NFS problem. I notice that there has been silence
>>>> on the problem since the 16th, so I assume that either this is a
>>>> hard bug to track down or you have been busy with higher priority
>>>> tasks. Is there anything I can do to help develop a solution to
>>>> this problem?
>>>
>>> Well, the only candidate explanation for the problem is that my
>>> assumption--that any time the server gets a stateid from the current
>>> boot instance that it doesn't recognize as an active stateid, it is safe
>>> for the server to return EXPIRED--is wrong.
>>>
>>> I don't immediately see why it's wrong, and based on the silence nobody
>>> else does either, but I'm not 100% convinced I'm right either.
>>>
>>> So one approach might be to add server code that makes a better effort
>>> to return EXPIRED only when we're sure it's a stateid from an expired
>>> client, and see if that solves your problem.
>>>
>>> Remind me, did you have an easy way to reproduce your problem?
>>
>> My silence is simply because I'm mystified as to how this can happen.
>
> So since the client's sending it with a READ, the client thinks that the
> stateid is still a valid open, lock, or delegation stateid, while the
> server thinks it's not. Hm.

I found this bug when I used "forget all locks" in the fault injection code I recently posted. Trond's fix works for me.

- Bryan

>
> --b.
>
>> Patching for it is trivial (see below).
>>
>> When the server tells us that our lease is expired, the normal behaviour
>> for the client is to re-establish the lease, and then proceed to recover
>> all known stateids. I don't see how we can 'miss' a stateid that then
>> needs to be recovered afterwards...
> --
> To unsubscribe from this list: send the line "unsubscribe linux-nfs" in
> the body of a message to [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html


2011-05-20 19:15:35

by Myklebust, Trond

[permalink] [raw]
Subject: Re: 2.6.38.6 - state manager constantly respawns

On Fri, 2011-05-20 at 14:59 -0400, Dr. J. Bruce Fields wrote:
> > Bruce,
> >
> > If the clientid expired, is it possible that the server may have handed
> > out the same numerical short clientid to someone else and that explains
> > why the RENEW is succeeding?
>
> Clientid's are created from a u32 counter that's sampled only under the
> state lock, so it sounds unlikely.
>
> I think more likely would be some bug affecting the lifetime of a
> stateid--e.g. if the server destroyed a lock stateid earlier than it
> should in some case, then this would happen. (Since, as I say, we
> assume EXPIRED for any stateid we don't recognize.)

Shouldn't that be a NFS4ERR_BAD_STATEID instead of NFS4ERR_EXPIRED? The
latter should really be reserved for the case where you know that this
stateid came from an expired lease.

--
Trond Myklebust
Linux NFS client maintainer

NetApp
[email protected]
http://www.netapp.com


2011-05-16 19:48:12

by Harry Edmon

[permalink] [raw]
Subject: Re: 2.6.38.6 - state manager constantly respawns

On 05/16/11 12:43, Trond Myklebust wrote:
> On Mon, 2011-05-16 at 12:36 -0700, Harry Edmon wrote:
>
>> On 05/16/11 12:22, Chuck Lever wrote:
>>
>>> On May 16, 2011, at 3:12 PM, Harry Edmon wrote:
>>>
>>>
>>>
>>>> Attached is 1000 lines of output from tshark when the problem is occurring. The client and server are connected by a private ethernet.
>>>>
>>>>
>>> Disappointing: tshark is not telling us the return codes. However, I see "PUTFH;READ" then "RENEW" in a loop, which indicates the state manager thread is being kicked off because of ongoing difficulties with state recovery. Is there a stuck application on that client?
>>>
>>> Try again with "tshark -V".
>>>
>>>
>> Here is the output from tshark -V (first 50,000 lines). Nothing
>> appears to be stuck, and as I said when I reboot the client into 2.6.32
>> the problem goes away, only to reappear when I reboot it back into 2.6.38.6.
>>
>>
> Possibly, but it definitely indicates a server bug. What kind of server
> are you using?
>
> Basically, the client is getting confused because when it sends a READ,
> the server is telling it that the lease has expired, then when it sends
> a RENEW, the same server replies that the lease is OK...
>
> Trond
>
The server is running the 2.6.38.6 kernel with Debian squeeze, just like
the client. The kernel config is attached.


--
Dr. Harry Edmon E-MAIL: [email protected]
206-543-0547 FAX: 206-543-0308 [email protected]
Director of IT, College of the Environment and
Director of Computing, Dept of Atmospheric Sciences
University of Washington, Box 351640, Seattle, WA 98195-1640


Attachments:
config-2.6.38.6 (63.48 kB)

2011-05-20 18:36:58

by Myklebust, Trond

[permalink] [raw]
Subject: Re: 2.6.38.6 - state manager constantly respawns

On Fri, 2011-05-20 at 13:52 -0400, Trond Myklebust wrote:
> On Fri, 2011-05-20 at 13:26 -0400, Dr. J. Bruce Fields wrote:
> > On Fri, May 20, 2011 at 09:20:47AM -0700, Harry Edmon wrote:
> > > On 05/16/11 13:53, Dr. J. Bruce Fields wrote:
> > > >Hm, so the renews all have clid 465ccc4d09000000, and the reads all have
> > > >a stateid (0, 465ccc4dc24c0a0000000000).
> > > >
> > > >So the first 4 bytes matching just tells me both were handed out by the
> > > >same server instance (so there was no server reboot in between); there's
> > > >no way for me to tell whether they really belong to the same client.
> > > >
> > > >The server does assume that any stateid from the current server instance
> > > >that no longer exists in its table is expired. I believe that's
> > > >correct, given a correctly functioning client, but perhaps I'm missing a
> > > >case.
> > > >
> > > >--b.
> > > I am very appreciative of the quick initial comments I receive from
> > > all of you on my NFS problem. I notice that there has been silence
> > > on the problem since the 16th, so I assume that either this is a
> > > hard bug to track down or you have been busy with higher priority
> > > tasks. Is there anything I can do to help develop a solution to
> > > this problem?
> >
> > Well, the only candidate explanation for the problem is that my
> > assumption--that any time the server gets a stateid from the current
> > boot instance that it doesn't recognize as an active stateid, it is safe
> > for the server to return EXPIRED--is wrong.
> >
> > I don't immediately see why it's wrong, and based on the silence nobody
> > else does either, but I'm not 100% convinced I'm right either.
> >
> > So one approach might be to add server code that makes a better effort
> > to return EXPIRED only when we're sure it's a stateid from an expired
> > client, and see if that solves your problem.
> >
> > Remind me, did you have an easy way to reproduce your problem?
>
> My silence is simply because I'm mystified as to how this can happen.
> Patching for it is trivial (see below).
>
> When the server tells us that our lease is expired, the normal behaviour
> for the client is to re-establish the lease, and then proceed to recover
> all known stateids. I don't see how we can 'miss' a stateid that then
> needs to be recovered afterwards...

Bruce,

If the clientid expired, is it possible that the server may have handed
out the same numerical short clientid to someone else and that explains
why the RENEW is succeeding?

--
Trond Myklebust
Linux NFS client maintainer

NetApp
[email protected]
http://www.netapp.com


2011-05-16 20:21:04

by J. Bruce Fields

[permalink] [raw]
Subject: Re: 2.6.38.6 - state manager constantly respawns

On Mon, May 16, 2011 at 03:54:16PM -0400, Trond Myklebust wrote:
> On Mon, 2011-05-16 at 12:48 -0700, Harry Edmon wrote:
> > On 05/16/11 12:43, Trond Myklebust wrote:
> > > On Mon, 2011-05-16 at 12:36 -0700, Harry Edmon wrote:
> > >
> > >> On 05/16/11 12:22, Chuck Lever wrote:
> > >>
> > >>> On May 16, 2011, at 3:12 PM, Harry Edmon wrote:
> > >>>
> > >>>
> > >>>
> > >>>> Attached is 1000 lines of output from tshark when the problem is occurring. The client and server are connected by a private ethernet.
> > >>>>
> > >>>>
> > >>> Disappointing: tshark is not telling us the return codes. However, I see "PUTFH;READ" then "RENEW" in a loop, which indicates the state manager thread is being kicked off because of ongoing difficulties with state recovery. Is there a stuck application on that client?
> > >>>
> > >>> Try again with "tshark -V".
> > >>>
> > >>>
> > >> Here is the output from tshark -V (first 50,000 lines). Nothing
> > >> appears to be stuck, and as I said when I reboot the client into 2.6.32
> > >> the problem goes away, only to reappear when I reboot it back into 2.6.38.6.
> > >>
> > >>
> > > Possibly, but it definitely indicates a server bug. What kind of server
> > > are you using?
> > >
> > > Basically, the client is getting confused because when it sends a READ,
> > > the server is telling it that the lease has expired, then when it sends
> > > a RENEW, the same server replies that the lease is OK...
> > >
> > > Trond
> > >
> > The server is running the 2.6.38.6 kernel with Debian squeeze, just like
> > the client. The kernel config is attached.
>
> Bruce, any idea how the server might get into this state?

So READ is getting ESTALE and RENEW is getting OK? And we're positive
that the stateid on the READ is derived from the clientid sent with the
RENEW?

OK, I'll look at the capture....

--b.

2011-05-20 17:26:44

by J. Bruce Fields

[permalink] [raw]
Subject: Re: 2.6.38.6 - state manager constantly respawns

On Fri, May 20, 2011 at 09:20:47AM -0700, Harry Edmon wrote:
> On 05/16/11 13:53, Dr. J. Bruce Fields wrote:
> >Hm, so the renews all have clid 465ccc4d09000000, and the reads all have
> >a stateid (0, 465ccc4dc24c0a0000000000).
> >
> >So the first 4 bytes matching just tells me both were handed out by the
> >same server instance (so there was no server reboot in between); there's
> >no way for me to tell whether they really belong to the same client.
> >
> >The server does assume that any stateid from the current server instance
> >that no longer exists in its table is expired. I believe that's
> >correct, given a correctly functioning client, but perhaps I'm missing a
> >case.
> >
> >--b.
> I am very appreciative of the quick initial comments I receive from
> all of you on my NFS problem. I notice that there has been silence
> on the problem since the 16th, so I assume that either this is a
> hard bug to track down or you have been busy with higher priority
> tasks. Is there anything I can do to help develop a solution to
> this problem?

Well, the only candidate explanation for the problem is that my
assumption--that any time the server gets a stateid from the current
boot instance that it doesn't recognize as an active stateid, it is safe
for the server to return EXPIRED--is wrong.

I don't immediately see why it's wrong, and based on the silence nobody
else does either, but I'm not 100% convinced I'm right either.

So one approach might be to add server code that makes a better effort
to return EXPIRED only when we're sure it's a stateid from an expired
client, and see if that solves your problem.

Remind me, did you have an easy way to reproduce your problem?

--b.

2011-05-20 18:59:39

by J. Bruce Fields

[permalink] [raw]
Subject: Re: 2.6.38.6 - state manager constantly respawns

On Fri, May 20, 2011 at 02:36:56PM -0400, Trond Myklebust wrote:
> On Fri, 2011-05-20 at 13:52 -0400, Trond Myklebust wrote:
> > On Fri, 2011-05-20 at 13:26 -0400, Dr. J. Bruce Fields wrote:
> > > On Fri, May 20, 2011 at 09:20:47AM -0700, Harry Edmon wrote:
> > > > On 05/16/11 13:53, Dr. J. Bruce Fields wrote:
> > > > >Hm, so the renews all have clid 465ccc4d09000000, and the reads all have
> > > > >a stateid (0, 465ccc4dc24c0a0000000000).
> > > > >
> > > > >So the first 4 bytes matching just tells me both were handed out by the
> > > > >same server instance (so there was no server reboot in between); there's
> > > > >no way for me to tell whether they really belong to the same client.
> > > > >
> > > > >The server does assume that any stateid from the current server instance
> > > > >that no longer exists in its table is expired. I believe that's
> > > > >correct, given a correctly functioning client, but perhaps I'm missing a
> > > > >case.
> > > > >
> > > > >--b.
> > > > I am very appreciative of the quick initial comments I receive from
> > > > all of you on my NFS problem. I notice that there has been silence
> > > > on the problem since the 16th, so I assume that either this is a
> > > > hard bug to track down or you have been busy with higher priority
> > > > tasks. Is there anything I can do to help develop a solution to
> > > > this problem?
> > >
> > > Well, the only candidate explanation for the problem is that my
> > > assumption--that any time the server gets a stateid from the current
> > > boot instance that it doesn't recognize as an active stateid, it is safe
> > > for the server to return EXPIRED--is wrong.
> > >
> > > I don't immediately see why it's wrong, and based on the silence nobody
> > > else does either, but I'm not 100% convinced I'm right either.
> > >
> > > So one approach might be to add server code that makes a better effort
> > > to return EXPIRED only when we're sure it's a stateid from an expired
> > > client, and see if that solves your problem.
> > >
> > > Remind me, did you have an easy way to reproduce your problem?
> >
> > My silence is simply because I'm mystified as to how this can happen.
> > Patching for it is trivial (see below).
> >
> > When the server tells us that our lease is expired, the normal behaviour
> > for the client is to re-establish the lease, and then proceed to recover
> > all known stateids. I don't see how we can 'miss' a stateid that then
> > needs to be recovered afterwards...
>
> Bruce,
>
> If the clientid expired, is it possible that the server may have handed
> out the same numerical short clientid to someone else and that explains
> why the RENEW is succeeding?

Clientid's are created from a u32 counter that's sampled only under the
state lock, so it sounds unlikely.

I think more likely would be some bug affecting the lifetime of a
stateid--e.g. if the server destroyed a lock stateid earlier than it
should in some case, then this would happen. (Since, as I say, we
assume EXPIRED for any stateid we don't recognize.)

--b.

2011-05-16 19:22:36

by Chuck Lever III

[permalink] [raw]
Subject: Re: 2.6.38.6 - state manager constantly respawns


On May 16, 2011, at 3:12 PM, Harry Edmon wrote:

> Attached is 1000 lines of output from tshark when the problem is occurring. The client and server are connected by a private ethernet.

Disappointing: tshark is not telling us the return codes. However, I see "PUTFH;READ" then "RENEW" in a loop, which indicates the state manager thread is being kicked off because of ongoing difficulties with state recovery. Is there a stuck application on that client?

Try again with "tshark -V".

>
> On 05/16/11 11:45, Chuck Lever wrote:
>> On May 16, 2011, at 2:40 PM, Harry Edmon wrote:
>>
>>
>>> I have a NFSv4 server and client running 2.6.38.6 with Debian squeeze. On my client kthreadd is running constantly, and my processes accounting file is full of entries with the PPID of kthreadd and the command being the IP number of the server with "-ma" appended, e.g.
>>>
>>> 192.168.1.12-ma
>>>
>>> I believe this is the nfsv4 state manager being constantly being respawned by kthreadd and quickly exiting. There are no log entries from the state manager (or anything else from NFS). When I reboot the system with the Debian provided 2.6.32 kernel the problem goes away. Does anyone have an idea why this would be occurring? I have included the kernel config file from the client.
>>>
>> One thing you could do to capture more information about the problem is to run a network trace on a client that is in this state. The procedures and error codes on the wire might be illuminating.
>>
>>
>
>
> --
> Dr. Harry Edmon E-MAIL: [email protected]
> 206-543-0547 FAX: 206-543-0308 [email protected]
> Director of IT, College of the Environment and
> Director of Computing, Dept of Atmospheric Sciences
> University of Washington, Box 351640, Seattle, WA 98195-1640
>
> <capture_1000.out.gz>

--
Chuck Lever
chuck[dot]lever[at]oracle[dot]com





2011-05-20 16:20:50

by Harry Edmon

[permalink] [raw]
Subject: Re: 2.6.38.6 - state manager constantly respawns

On 05/16/11 13:53, Dr. J. Bruce Fields wrote:
> On Mon, May 16, 2011 at 04:20:59PM -0400, Dr. J. Bruce Fields wrote:
>
>> On Mon, May 16, 2011 at 03:54:16PM -0400, Trond Myklebust wrote:
>>
>>> On Mon, 2011-05-16 at 12:48 -0700, Harry Edmon wrote:
>>>
>>>> On 05/16/11 12:43, Trond Myklebust wrote:
>>>>
>>>>> On Mon, 2011-05-16 at 12:36 -0700, Harry Edmon wrote:
>>>>>
>>>>>
>>>>>> On 05/16/11 12:22, Chuck Lever wrote:
>>>>>>
>>>>>>
>>>>>>> On May 16, 2011, at 3:12 PM, Harry Edmon wrote:
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>> Attached is 1000 lines of output from tshark when the problem is occurring. The client and server are connected by a private ethernet.
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>> Disappointing: tshark is not telling us the return codes. However, I see "PUTFH;READ" then "RENEW" in a loop, which indicates the state manager thread is being kicked off because of ongoing difficulties with state recovery. Is there a stuck application on that client?
>>>>>>>
>>>>>>> Try again with "tshark -V".
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>> Here is the output from tshark -V (first 50,000 lines). Nothing
>>>>>> appears to be stuck, and as I said when I reboot the client into 2.6.32
>>>>>> the problem goes away, only to reappear when I reboot it back into 2.6.38.6.
>>>>>>
>>>>>>
>>>>>>
>>>>> Possibly, but it definitely indicates a server bug. What kind of server
>>>>> are you using?
>>>>>
>>>>> Basically, the client is getting confused because when it sends a READ,
>>>>> the server is telling it that the lease has expired, then when it sends
>>>>> a RENEW, the same server replies that the lease is OK...
>>>>>
>>>>> Trond
>>>>>
>>>>>
>>>> The server is running the 2.6.38.6 kernel with Debian squeeze, just like
>>>> the client. The kernel config is attached.
>>>>
>>> Bruce, any idea how the server might get into this state?
>>>
>> So READ is getting ESTALE
>>
> Err, sorry, EXPIRED.
>
>
>> and RENEW is getting OK? And we're positive
>> that the stateid on the READ is derived from the clientid sent with the
>> RENEW?
>>
>> OK, I'll look at the capture....
>>
> Hm, so the renews all have clid 465ccc4d09000000, and the reads all have
> a stateid (0, 465ccc4dc24c0a0000000000).
>
> So the first 4 bytes matching just tells me both were handed out by the
> same server instance (so there was no server reboot in between); there's
> no way for me to tell whether they really belong to the same client.
>
> The server does assume that any stateid from the current server instance
> that no longer exists in its table is expired. I believe that's
> correct, given a correctly functioning client, but perhaps I'm missing a
> case.
>
> --b.
>
I am very appreciative of the quick initial comments I receive from all
of you on my NFS problem. I notice that there has been silence on the
problem since the 16th, so I assume that either this is a hard bug to
track down or you have been busy with higher priority tasks. Is there
anything I can do to help develop a solution to this problem?

--
Dr. Harry Edmon E-MAIL: [email protected]
206-543-0547 FAX: 206-543-0308 [email protected]
Director of IT, College of the Environment and
Director of Computing, Dept of Atmospheric Sciences
University of Washington, Box 351640, Seattle, WA 98195-1640


2011-05-20 20:27:48

by Myklebust, Trond

[permalink] [raw]
Subject: Re: 2.6.38.6 - state manager constantly respawns

On Fri, 2011-05-20 at 13:23 -0700, Harry Edmon wrote:
> On 05/20/11 13:11, Trond Myklebust wrote:
> > On Fri, 2011-05-20 at 12:44 -0700, Harry Edmon wrote:
> >
> >>> Once a minute is rather unusual... What kind of server are you running
> >>> against?
> >>>
> >>> If it is a Linux server, what is the value contained in the virtual file
> >>> "/proc/fs/nfsd/nfsv4leasetime" ?
> >>>
> >>>
> >>>
> >> Same as before - Debian Squeeze running 2.6.38.6. The value of
> >> /proc/fs/nfsd/nfsv4leasetime is 90 and is not something I changed.
> >>
> > OK... Does 'nfsstat' on the server show any 'delegreturn' updates around
> > the time when the state manager thread runs? It could just be that it is
> > reaping all your unused delegations.
> >
> >
> That number seems to be increasing all the time, whether or not the
> state manager process appears in the accounting file. And this is only
> the one NFS client for this sever.
>

OK. If your client is using delegations heavily then that would indeed
explain the 1 minute delay between state manager runs, since the renew
daemon runs once a minute, and will mark any unused delegations for
reaping by the state manager.

--
Trond Myklebust
Linux NFS client maintainer

NetApp
[email protected]
http://www.netapp.com


2011-05-16 20:53:54

by J. Bruce Fields

[permalink] [raw]
Subject: Re: 2.6.38.6 - state manager constantly respawns

On Mon, May 16, 2011 at 04:20:59PM -0400, Dr. J. Bruce Fields wrote:
> On Mon, May 16, 2011 at 03:54:16PM -0400, Trond Myklebust wrote:
> > On Mon, 2011-05-16 at 12:48 -0700, Harry Edmon wrote:
> > > On 05/16/11 12:43, Trond Myklebust wrote:
> > > > On Mon, 2011-05-16 at 12:36 -0700, Harry Edmon wrote:
> > > >
> > > >> On 05/16/11 12:22, Chuck Lever wrote:
> > > >>
> > > >>> On May 16, 2011, at 3:12 PM, Harry Edmon wrote:
> > > >>>
> > > >>>
> > > >>>
> > > >>>> Attached is 1000 lines of output from tshark when the problem is occurring. The client and server are connected by a private ethernet.
> > > >>>>
> > > >>>>
> > > >>> Disappointing: tshark is not telling us the return codes. However, I see "PUTFH;READ" then "RENEW" in a loop, which indicates the state manager thread is being kicked off because of ongoing difficulties with state recovery. Is there a stuck application on that client?
> > > >>>
> > > >>> Try again with "tshark -V".
> > > >>>
> > > >>>
> > > >> Here is the output from tshark -V (first 50,000 lines). Nothing
> > > >> appears to be stuck, and as I said when I reboot the client into 2.6.32
> > > >> the problem goes away, only to reappear when I reboot it back into 2.6.38.6.
> > > >>
> > > >>
> > > > Possibly, but it definitely indicates a server bug. What kind of server
> > > > are you using?
> > > >
> > > > Basically, the client is getting confused because when it sends a READ,
> > > > the server is telling it that the lease has expired, then when it sends
> > > > a RENEW, the same server replies that the lease is OK...
> > > >
> > > > Trond
> > > >
> > > The server is running the 2.6.38.6 kernel with Debian squeeze, just like
> > > the client. The kernel config is attached.
> >
> > Bruce, any idea how the server might get into this state?
>
> So READ is getting ESTALE

Err, sorry, EXPIRED.

> and RENEW is getting OK? And we're positive
> that the stateid on the READ is derived from the clientid sent with the
> RENEW?
>
> OK, I'll look at the capture....

Hm, so the renews all have clid 465ccc4d09000000, and the reads all have
a stateid (0, 465ccc4dc24c0a0000000000).

So the first 4 bytes matching just tells me both were handed out by the
same server instance (so there was no server reboot in between); there's
no way for me to tell whether they really belong to the same client.

The server does assume that any stateid from the current server instance
that no longer exists in its table is expired. I believe that's
correct, given a correctly functioning client, but perhaps I'm missing a
case.

--b.

2011-05-16 20:21:47

by Chuck Lever III

[permalink] [raw]
Subject: Re: 2.6.38.6 - state manager constantly respawns


On May 16, 2011, at 3:43 PM, Trond Myklebust wrote:

> On Mon, 2011-05-16 at 12:36 -0700, Harry Edmon wrote:
>> On 05/16/11 12:22, Chuck Lever wrote:
>>> On May 16, 2011, at 3:12 PM, Harry Edmon wrote:
>>>
>>>
>>>> Attached is 1000 lines of output from tshark when the problem is occurring. The client and server are connected by a private ethernet.
>>>>
>>> Disappointing: tshark is not telling us the return codes. However, I see "PUTFH;READ" then "RENEW" in a loop, which indicates the state manager thread is being kicked off because of ongoing difficulties with state recovery. Is there a stuck application on that client?
>>>
>>> Try again with "tshark -V".
>>>
>> Here is the output from tshark -V (first 50,000 lines). Nothing
>> appears to be stuck, and as I said when I reboot the client into 2.6.32
>> the problem goes away, only to reappear when I reboot it back into 2.6.38.6.
>>
>
> Possibly, but it definitely indicates a server bug. What kind of server
> are you using?
>
> Basically, the client is getting confused because when it sends a READ,
> the server is telling it that the lease has expired, then when it sends
> a RENEW, the same server replies that the lease is OK...

I've seen this during migration recovery testing. The client may be testing the wrong client ID.

But I wonder if it's really worth doing that separate RENEW. I've seen the client send a RENEW after it gets STALE_STATEID. Would RENEW really tell the client anything in that case?

--
Chuck Lever
chuck[dot]lever[at]oracle[dot]com





2011-05-16 19:12:49

by Harry Edmon

[permalink] [raw]
Subject: Re: 2.6.38.6 - state manager constantly respawns

Attached is 1000 lines of output from tshark when the problem is
occurring. The client and server are connected by a private ethernet.

On 05/16/11 11:45, Chuck Lever wrote:
> On May 16, 2011, at 2:40 PM, Harry Edmon wrote:
>
>
>> I have a NFSv4 server and client running 2.6.38.6 with Debian squeeze. On my client kthreadd is running constantly, and my processes accounting file is full of entries with the PPID of kthreadd and the command being the IP number of the server with "-ma" appended, e.g.
>>
>> 192.168.1.12-ma
>>
>> I believe this is the nfsv4 state manager being constantly being respawned by kthreadd and quickly exiting. There are no log entries from the state manager (or anything else from NFS). When I reboot the system with the Debian provided 2.6.32 kernel the problem goes away. Does anyone have an idea why this would be occurring? I have included the kernel config file from the client.
>>
> One thing you could do to capture more information about the problem is to run a network trace on a client that is in this state. The procedures and error codes on the wire might be illuminating.
>
>


--
Dr. Harry Edmon E-MAIL: [email protected]
206-543-0547 FAX: 206-543-0308 [email protected]
Director of IT, College of the Environment and
Director of Computing, Dept of Atmospheric Sciences
University of Washington, Box 351640, Seattle, WA 98195-1640


Attachments:
capture_1000.out.gz (8.35 kB)

2011-05-20 19:39:46

by Andy Adamson

[permalink] [raw]
Subject: Re: 2.6.38.6 - state manager constantly respawns


On May 20, 2011, at 3:29 PM, Harry Edmon wrote:

> On 05/20/11 10:52, Trond Myklebust wrote:
>> On Fri, 2011-05-20 at 13:26 -0400, Dr. J. Bruce Fields wrote:
>>
>>> On Fri, May 20, 2011 at 09:20:47AM -0700, Harry Edmon wrote:
>>>
>>>> On 05/16/11 13:53, Dr. J. Bruce Fields wrote:
>>>>
>>>>> Hm, so the renews all have clid 465ccc4d09000000, and the reads all have
>>>>> a stateid (0, 465ccc4dc24c0a0000000000).
>>>>>
>>>>> So the first 4 bytes matching just tells me both were handed out by the
>>>>> same server instance (so there was no server reboot in between); there's
>>>>> no way for me to tell whether they really belong to the same client.
>>>>>
>>>>> The server does assume that any stateid from the current server instance
>>>>> that no longer exists in its table is expired. I believe that's
>>>>> correct, given a correctly functioning client, but perhaps I'm missing a
>>>>> case.
>>>>>
>>>>> --b.
>>>>>
>>>> I am very appreciative of the quick initial comments I receive from
>>>> all of you on my NFS problem. I notice that there has been silence
>>>> on the problem since the 16th, so I assume that either this is a
>>>> hard bug to track down or you have been busy with higher priority
>>>> tasks. Is there anything I can do to help develop a solution to
>>>> this problem?
>>>>
>>> Well, the only candidate explanation for the problem is that my
>>> assumption--that any time the server gets a stateid from the current
>>> boot instance that it doesn't recognize as an active stateid, it is safe
>>> for the server to return EXPIRED--is wrong.
>>>
>>> I don't immediately see why it's wrong, and based on the silence nobody
>>> else does either, but I'm not 100% convinced I'm right either.
>>>
>>> So one approach might be to add server code that makes a better effort
>>> to return EXPIRED only when we're sure it's a stateid from an expired
>>> client, and see if that solves your problem.
>>>
>>> Remind me, did you have an easy way to reproduce your problem?
>>>
>> My silence is simply because I'm mystified as to how this can happen.
>> Patching for it is trivial (see below).
>>
>> When the server tells us that our lease is expired, the normal behaviour
>> for the client is to re-establish the lease, and then proceed to recover
>> all known stateids. I don't see how we can 'miss' a stateid that then
>> needs to be recovered afterwards...
>>
>> Cheers
>> Trond
>>
>> 8<----------------------------------------------------------------------------
>> From 920ddb153f28717be363f6e87dde24ef2a8d0ce2 Mon Sep 17 00:00:00 2001
>> From: Trond Myklebust<[email protected]>
>> Date: Fri, 20 May 2011 13:44:02 -0400
>> Subject: [PATCH] NFSv4: Handle expired stateids when the lease is still valid
>>
>> Currently, if the server returns NFS4ERR_EXPIRED in reply to a READ or
>> WRITE, but the RENEW test determines that the lease is still active, we
>> fail to recover and end up looping forever in a READ/WRITE + RENEW death
>> spiral.
>>
>> Signed-off-by: Trond Myklebust<[email protected]>
>> ---
>> fs/nfs/nfs4proc.c | 9 +++++++--
>> 1 files changed, 7 insertions(+), 2 deletions(-)
>>
>> diff --git a/fs/nfs/nfs4proc.c b/fs/nfs/nfs4proc.c
>> index cf1b339..d0e15db 100644
>> --- a/fs/nfs/nfs4proc.c
>> +++ b/fs/nfs/nfs4proc.c
>> @@ -267,9 +267,11 @@ static int nfs4_handle_exception(struct nfs_server *server, int errorcode, struc
>> break;
>> nfs4_schedule_stateid_recovery(server, state);
>> goto wait_on_recovery;
>> + case -NFS4ERR_EXPIRED:
>> + if (state != NULL)
>> + nfs4_schedule_stateid_recovery(server, state);
>> case -NFS4ERR_STALE_STATEID:
>> case -NFS4ERR_STALE_CLIENTID:
>> - case -NFS4ERR_EXPIRED:
>> nfs4_schedule_lease_recovery(clp);
>> goto wait_on_recovery;
>> #if defined(CONFIG_NFS_V4_1)
>> @@ -3670,9 +3672,11 @@ nfs4_async_handle_error(struct rpc_task *task, const struct nfs_server *server,
>> break;
>> nfs4_schedule_stateid_recovery(server, state);
>> goto wait_on_recovery;
>> + case -NFS4ERR_EXPIRED:
>> + if (state != NULL)
>> + nfs4_schedule_stateid_recovery(server, state);
>> case -NFS4ERR_STALE_STATEID:
>> case -NFS4ERR_STALE_CLIENTID:
>> - case -NFS4ERR_EXPIRED:
>> nfs4_schedule_lease_recovery(clp);
>> goto wait_on_recovery;
>> #if defined(CONFIG_NFS_V4_1)
>> @@ -4543,6 +4547,7 @@ int nfs4_lock_delegation_recall(struct nfs4_state *state, struct file_lock *fl)
>> case -ESTALE:
>> goto out;
>> case -NFS4ERR_EXPIRED:
>> + nfs4_schedule_stateid_recovery(server, state);
>> case -NFS4ERR_STALE_CLIENTID:
>> case -NFS4ERR_STALE_STATEID:
>> nfs4_schedule_lease_recovery(server->nfs_client);
>>
> I installed this patch on my client, and now I am seeing the state manager appear in the process accounting file about once a minute rather that the constant respawning I saw earlier. Is once a minute normal, or is there still a problem?

The state manager sends the lease renew heart-beat. It should spawn every lease period unless a lease-renewing operation (one with state) happens to be sent.

-->Andy

>
> --
> Dr. Harry Edmon E-MAIL: [email protected]
> 206-543-0547 FAX: 206-543-0308 [email protected]
> Director of IT, College of the Environment and
> Director of Computing, Dept of Atmospheric Sciences
> University of Washington, Box 351640, Seattle, WA 98195-1640
>
> --
> To unsubscribe from this list: send the line "unsubscribe linux-nfs" in
> the body of a message to [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html


2011-05-20 19:40:19

by Myklebust, Trond

[permalink] [raw]
Subject: Re: 2.6.38.6 - state manager constantly respawns

On Fri, 2011-05-20 at 12:29 -0700, Harry Edmon wrote:
> On 05/20/11 10:52, Trond Myklebust wrote:
> > On Fri, 2011-05-20 at 13:26 -0400, Dr. J. Bruce Fields wrote:
> >
> >> On Fri, May 20, 2011 at 09:20:47AM -0700, Harry Edmon wrote:
> >>
> >>> On 05/16/11 13:53, Dr. J. Bruce Fields wrote:
> >>>
> >>>> Hm, so the renews all have clid 465ccc4d09000000, and the reads all have
> >>>> a stateid (0, 465ccc4dc24c0a0000000000).
> >>>>
> >>>> So the first 4 bytes matching just tells me both were handed out by the
> >>>> same server instance (so there was no server reboot in between); there's
> >>>> no way for me to tell whether they really belong to the same client.
> >>>>
> >>>> The server does assume that any stateid from the current server instance
> >>>> that no longer exists in its table is expired. I believe that's
> >>>> correct, given a correctly functioning client, but perhaps I'm missing a
> >>>> case.
> >>>>
> >>>> --b.
> >>>>
> >>> I am very appreciative of the quick initial comments I receive from
> >>> all of you on my NFS problem. I notice that there has been silence
> >>> on the problem since the 16th, so I assume that either this is a
> >>> hard bug to track down or you have been busy with higher priority
> >>> tasks. Is there anything I can do to help develop a solution to
> >>> this problem?
> >>>
> >> Well, the only candidate explanation for the problem is that my
> >> assumption--that any time the server gets a stateid from the current
> >> boot instance that it doesn't recognize as an active stateid, it is safe
> >> for the server to return EXPIRED--is wrong.
> >>
> >> I don't immediately see why it's wrong, and based on the silence nobody
> >> else does either, but I'm not 100% convinced I'm right either.
> >>
> >> So one approach might be to add server code that makes a better effort
> >> to return EXPIRED only when we're sure it's a stateid from an expired
> >> client, and see if that solves your problem.
> >>
> >> Remind me, did you have an easy way to reproduce your problem?
> >>
> > My silence is simply because I'm mystified as to how this can happen.
> > Patching for it is trivial (see below).
> >
> > When the server tells us that our lease is expired, the normal behaviour
> > for the client is to re-establish the lease, and then proceed to recover
> > all known stateids. I don't see how we can 'miss' a stateid that then
> > needs to be recovered afterwards...
> >
> > Cheers
> > Trond
> >
> > 8<----------------------------------------------------------------------------
> > From 920ddb153f28717be363f6e87dde24ef2a8d0ce2 Mon Sep 17 00:00:00 2001
> > From: Trond Myklebust<[email protected]>
> > Date: Fri, 20 May 2011 13:44:02 -0400
> > Subject: [PATCH] NFSv4: Handle expired stateids when the lease is still valid
> >
> > Currently, if the server returns NFS4ERR_EXPIRED in reply to a READ or
> > WRITE, but the RENEW test determines that the lease is still active, we
> > fail to recover and end up looping forever in a READ/WRITE + RENEW death
> > spiral.
> >
> > Signed-off-by: Trond Myklebust<[email protected]>
> > ---
> > fs/nfs/nfs4proc.c | 9 +++++++--
> > 1 files changed, 7 insertions(+), 2 deletions(-)
> >
> > diff --git a/fs/nfs/nfs4proc.c b/fs/nfs/nfs4proc.c
> > index cf1b339..d0e15db 100644
> > --- a/fs/nfs/nfs4proc.c
> > +++ b/fs/nfs/nfs4proc.c
> > @@ -267,9 +267,11 @@ static int nfs4_handle_exception(struct nfs_server *server, int errorcode, struc
> > break;
> > nfs4_schedule_stateid_recovery(server, state);
> > goto wait_on_recovery;
> > + case -NFS4ERR_EXPIRED:
> > + if (state != NULL)
> > + nfs4_schedule_stateid_recovery(server, state);
> > case -NFS4ERR_STALE_STATEID:
> > case -NFS4ERR_STALE_CLIENTID:
> > - case -NFS4ERR_EXPIRED:
> > nfs4_schedule_lease_recovery(clp);
> > goto wait_on_recovery;
> > #if defined(CONFIG_NFS_V4_1)
> > @@ -3670,9 +3672,11 @@ nfs4_async_handle_error(struct rpc_task *task, const struct nfs_server *server,
> > break;
> > nfs4_schedule_stateid_recovery(server, state);
> > goto wait_on_recovery;
> > + case -NFS4ERR_EXPIRED:
> > + if (state != NULL)
> > + nfs4_schedule_stateid_recovery(server, state);
> > case -NFS4ERR_STALE_STATEID:
> > case -NFS4ERR_STALE_CLIENTID:
> > - case -NFS4ERR_EXPIRED:
> > nfs4_schedule_lease_recovery(clp);
> > goto wait_on_recovery;
> > #if defined(CONFIG_NFS_V4_1)
> > @@ -4543,6 +4547,7 @@ int nfs4_lock_delegation_recall(struct nfs4_state *state, struct file_lock *fl)
> > case -ESTALE:
> > goto out;
> > case -NFS4ERR_EXPIRED:
> > + nfs4_schedule_stateid_recovery(server, state);
> > case -NFS4ERR_STALE_CLIENTID:
> > case -NFS4ERR_STALE_STATEID:
> > nfs4_schedule_lease_recovery(server->nfs_client);
> >
> I installed this patch on my client, and now I am seeing the state
> manager appear in the process accounting file about once a minute rather
> that the constant respawning I saw earlier. Is once a minute normal, or
> is there still a problem?

Once a minute is rather unusual... What kind of server are you running
against?

If it is a Linux server, what is the value contained in the virtual file
"/proc/fs/nfsd/nfsv4leasetime" ?

--
Trond Myklebust
Linux NFS client maintainer

NetApp
[email protected]
http://www.netapp.com


2011-05-16 20:33:52

by Myklebust, Trond

[permalink] [raw]
Subject: Re: 2.6.38.6 - state manager constantly respawns

On Mon, 2011-05-16 at 16:21 -0400, Chuck Lever wrote:
> On May 16, 2011, at 3:43 PM, Trond Myklebust wrote:
>
> > On Mon, 2011-05-16 at 12:36 -0700, Harry Edmon wrote:
> >> On 05/16/11 12:22, Chuck Lever wrote:
> >>> On May 16, 2011, at 3:12 PM, Harry Edmon wrote:
> >>>
> >>>
> >>>> Attached is 1000 lines of output from tshark when the problem is occurring. The client and server are connected by a private ethernet.
> >>>>
> >>> Disappointing: tshark is not telling us the return codes. However, I see "PUTFH;READ" then "RENEW" in a loop, which indicates the state manager thread is being kicked off because of ongoing difficulties with state recovery. Is there a stuck application on that client?
> >>>
> >>> Try again with "tshark -V".
> >>>
> >> Here is the output from tshark -V (first 50,000 lines). Nothing
> >> appears to be stuck, and as I said when I reboot the client into 2.6.32
> >> the problem goes away, only to reappear when I reboot it back into 2.6.38.6.
> >>
> >
> > Possibly, but it definitely indicates a server bug. What kind of server
> > are you using?
> >
> > Basically, the client is getting confused because when it sends a READ,
> > the server is telling it that the lease has expired, then when it sends
> > a RENEW, the same server replies that the lease is OK...
>
> I've seen this during migration recovery testing. The client may be testing the wrong client ID.
>
> But I wonder if it's really worth doing that separate RENEW. I've seen the client send a RENEW after it gets STALE_STATEID. Would RENEW really tell the client anything in that case?

It is needed.

Without the RENEW, we have no idea whether or not we need to do a full
state recovery. Running a full recovery when we don't have to is _bad_,
and will usually cause us to lose delegations and may possibly even
cause us to lose locks.

--
Trond Myklebust
Linux NFS client maintainer

NetApp
[email protected]
http://www.netapp.com


2011-05-20 17:52:44

by Myklebust, Trond

[permalink] [raw]
Subject: Re: 2.6.38.6 - state manager constantly respawns

On Fri, 2011-05-20 at 13:26 -0400, Dr. J. Bruce Fields wrote:
> On Fri, May 20, 2011 at 09:20:47AM -0700, Harry Edmon wrote:
> > On 05/16/11 13:53, Dr. J. Bruce Fields wrote:
> > >Hm, so the renews all have clid 465ccc4d09000000, and the reads all have
> > >a stateid (0, 465ccc4dc24c0a0000000000).
> > >
> > >So the first 4 bytes matching just tells me both were handed out by the
> > >same server instance (so there was no server reboot in between); there's
> > >no way for me to tell whether they really belong to the same client.
> > >
> > >The server does assume that any stateid from the current server instance
> > >that no longer exists in its table is expired. I believe that's
> > >correct, given a correctly functioning client, but perhaps I'm missing a
> > >case.
> > >
> > >--b.
> > I am very appreciative of the quick initial comments I receive from
> > all of you on my NFS problem. I notice that there has been silence
> > on the problem since the 16th, so I assume that either this is a
> > hard bug to track down or you have been busy with higher priority
> > tasks. Is there anything I can do to help develop a solution to
> > this problem?
>
> Well, the only candidate explanation for the problem is that my
> assumption--that any time the server gets a stateid from the current
> boot instance that it doesn't recognize as an active stateid, it is safe
> for the server to return EXPIRED--is wrong.
>
> I don't immediately see why it's wrong, and based on the silence nobody
> else does either, but I'm not 100% convinced I'm right either.
>
> So one approach might be to add server code that makes a better effort
> to return EXPIRED only when we're sure it's a stateid from an expired
> client, and see if that solves your problem.
>
> Remind me, did you have an easy way to reproduce your problem?

My silence is simply because I'm mystified as to how this can happen.
Patching for it is trivial (see below).

When the server tells us that our lease is expired, the normal behaviour
for the client is to re-establish the lease, and then proceed to recover
all known stateids. I don't see how we can 'miss' a stateid that then
needs to be recovered afterwards...

Cheers
Trond

8<----------------------------------------------------------------------------

2011-05-16 18:45:57

by Chuck Lever III

[permalink] [raw]
Subject: Re: 2.6.38.6 - state manager constantly respawns


On May 16, 2011, at 2:40 PM, Harry Edmon wrote:

> I have a NFSv4 server and client running 2.6.38.6 with Debian squeeze. On my client kthreadd is running constantly, and my processes accounting file is full of entries with the PPID of kthreadd and the command being the IP number of the server with "-ma" appended, e.g.
>
> 192.168.1.12-ma
>
> I believe this is the nfsv4 state manager being constantly being respawned by kthreadd and quickly exiting. There are no log entries from the state manager (or anything else from NFS). When I reboot the system with the Debian provided 2.6.32 kernel the problem goes away. Does anyone have an idea why this would be occurring? I have included the kernel config file from the client.

One thing you could do to capture more information about the problem is to run a network trace on a client that is in this state. The procedures and error codes on the wire might be illuminating.

--
Chuck Lever
chuck[dot]lever[at]oracle[dot]com





2011-05-16 19:54:17

by Myklebust, Trond

[permalink] [raw]
Subject: Re: 2.6.38.6 - state manager constantly respawns

On Mon, 2011-05-16 at 12:48 -0700, Harry Edmon wrote:
> On 05/16/11 12:43, Trond Myklebust wrote:
> > On Mon, 2011-05-16 at 12:36 -0700, Harry Edmon wrote:
> >
> >> On 05/16/11 12:22, Chuck Lever wrote:
> >>
> >>> On May 16, 2011, at 3:12 PM, Harry Edmon wrote:
> >>>
> >>>
> >>>
> >>>> Attached is 1000 lines of output from tshark when the problem is occurring. The client and server are connected by a private ethernet.
> >>>>
> >>>>
> >>> Disappointing: tshark is not telling us the return codes. However, I see "PUTFH;READ" then "RENEW" in a loop, which indicates the state manager thread is being kicked off because of ongoing difficulties with state recovery. Is there a stuck application on that client?
> >>>
> >>> Try again with "tshark -V".
> >>>
> >>>
> >> Here is the output from tshark -V (first 50,000 lines). Nothing
> >> appears to be stuck, and as I said when I reboot the client into 2.6.32
> >> the problem goes away, only to reappear when I reboot it back into 2.6.38.6.
> >>
> >>
> > Possibly, but it definitely indicates a server bug. What kind of server
> > are you using?
> >
> > Basically, the client is getting confused because when it sends a READ,
> > the server is telling it that the lease has expired, then when it sends
> > a RENEW, the same server replies that the lease is OK...
> >
> > Trond
> >
> The server is running the 2.6.38.6 kernel with Debian squeeze, just like
> the client. The kernel config is attached.

Bruce, any idea how the server might get into this state?

--
Trond Myklebust
Linux NFS client maintainer

NetApp
[email protected]
http://www.netapp.com


2011-05-16 20:37:25

by Harry Edmon

[permalink] [raw]
Subject: Re: 2.6.38.6 - state manager constantly respawns

On 05/16/11 13:33, Trond Myklebust wrote:
> On Mon, 2011-05-16 at 16:21 -0400, Chuck Lever wrote:
>
>> On May 16, 2011, at 3:43 PM, Trond Myklebust wrote:
>>
>>
>>> On Mon, 2011-05-16 at 12:36 -0700, Harry Edmon wrote:
>>>
>>>> On 05/16/11 12:22, Chuck Lever wrote:
>>>>
>>>>> On May 16, 2011, at 3:12 PM, Harry Edmon wrote:
>>>>>
>>>>>
>>>>>
>>>>>> Attached is 1000 lines of output from tshark when the problem is occurring. The client and server are connected by a private ethernet.
>>>>>>
>>>>>>
>>>>> Disappointing: tshark is not telling us the return codes. However, I see "PUTFH;READ" then "RENEW" in a loop, which indicates the state manager thread is being kicked off because of ongoing difficulties with state recovery. Is there a stuck application on that client?
>>>>>
>>>>> Try again with "tshark -V".
>>>>>
>>>>>
>>>> Here is the output from tshark -V (first 50,000 lines). Nothing
>>>> appears to be stuck, and as I said when I reboot the client into 2.6.32
>>>> the problem goes away, only to reappear when I reboot it back into 2.6.38.6.
>>>>
>>>>
>>> Possibly, but it definitely indicates a server bug. What kind of server
>>> are you using?
>>>
>>> Basically, the client is getting confused because when it sends a READ,
>>> the server is telling it that the lease has expired, then when it sends
>>> a RENEW, the same server replies that the lease is OK...
>>>
>> I've seen this during migration recovery testing. The client may be testing the wrong client ID.
>>
>> But I wonder if it's really worth doing that separate RENEW. I've seen the client send a RENEW after it gets STALE_STATEID. Would RENEW really tell the client anything in that case?
>>
> It is needed.
>
> Without the RENEW, we have no idea whether or not we need to do a full
> state recovery. Running a full recovery when we don't have to is _bad_,
> and will usually cause us to lose delegations and may possibly even
> cause us to lose locks.
>
>
By the way, this is not the only client/server running 2.6.38 that I
have this problem on. It is occurring on other random ones I
maintain. This example is happens to be the cleanest one I have, this
NFS server is only talking to this specific NFS client over a private
network.
--

Dr. Harry Edmon E-MAIL: [email protected]
206-543-0547 FAX: 206-543-0308 [email protected]
Director of IT, College of the Environment and
Director of Computing, Dept of Atmospheric Sciences
University of Washington, Box 351640, Seattle, WA 98195-1640