Hello everyone,
we are administrating an NFS high-availability cluster running on
SLES11SP1 with kernel 2.6.32.59. Just recently, one of the cluster
machines was updated to SLES11SP3 with kernel 3.0.82.
We are now experiencing severe hangs on NFS clients when the SLES11SP3
server is running the NFS services. An strace on the hanging processes
on the client side show that is is waiting up to 60+ seconds for a
"utime()" call to complete.
The problem we see is matching the problem described in the thread "v3.5
nfsd4 regression; utime sometimes takes 40+ seconds to return". If the
NFS server is running on SLES11SP3, the little test program provided in
this tread hangs at the "utime()" call for 60+ seconds. It hangs each
time it is run! It finishes right away with 0 seconds delay is SLES11SP1
is providing NFS services, each time.
Now, in the serverside logfiles of SLES11SP3 we see these messages (not
so on SP1):
--------------
kernel: [99381.184976] RPC: AUTH_GSS upcall timed out.
kernel: [99381.184978] Please check user daemon is running.
--------------
We have always been running the NFS server without rpc.gssd on the
server side, as the init script for the nfsserver also does not start
rpc.gssd.
Once we started rpc.gssd on the SLES11SP3 server, using the test utility
on the client shows that the first call to "utime()" succeeds right
away, the second call takes ~25s to complete. But now, any consecutive
runs of the utility finish with no more delay.
So can anyone confirm that with kernel 3.0+ the rpc.gssd daemon is also
required on the server side for correct operation?
Has there been a change between kernel 2.6.32.59 and 3.0.x?
Thus, is the init script of the nfsserver in SLES11SP3 indeed missing to
start rpc.gssd?
Thank you for your help!
Best regards,
--
Dipl.-Ing. Joschi Brauchle, M.S.
Institute for Communications Engineering (LNT)
Technische Universitaet Muenchen (TUM)
80290 Munich, Germany
Tel (work): +49 89 289-23474
Fax (work): +49 89 289-23490
E-mail: [email protected]
Web: http://www.lnt.ei.tum.de/
Am 10.09.2013 um 22:35 schrieb "J. Bruce Fields" <[email protected]>:
> On Tue, Sep 10, 2013 at 08:49:05PM +0200, Joschi Brauchle wrote:
>> Hello everyone,
>>
>> we are administrating an NFS high-availability cluster running on
>> SLES11SP1 with kernel 2.6.32.59. Just recently, one of the cluster
>> machines was updated to SLES11SP3 with kernel 3.0.82.
>>
>>
>> We are now experiencing severe hangs on NFS clients when the
>> SLES11SP3 server is running the NFS services. An strace on the
>> hanging processes on the client side show that is is waiting up to
>> 60+ seconds for a "utime()" call to complete.
>>
>>
>> The problem we see is matching the problem described in the thread
>> "v3.5 nfsd4 regression; utime sometimes takes 40+ seconds to
>> return". If the NFS server is running on SLES11SP3, the little test
>> program provided in this tread hangs at the "utime()" call for 60+
>> seconds. It hangs each time it is run! It finishes right away with 0
>> seconds delay is SLES11SP1 is providing NFS services, each time.
>>
>>
>> Now, in the serverside logfiles of SLES11SP3 we see these messages
>> (not so on SP1):
>> --------------
>> kernel: [99381.184976] RPC: AUTH_GSS upcall timed out.
>> kernel: [99381.184978] Please check user daemon is running.
>> --------------
>>
>> We have always been running the NFS server without rpc.gssd on the
>> server side, as the init script for the nfsserver also does not
>> start rpc.gssd.
>>
>>
>> Once we started rpc.gssd on the SLES11SP3 server, using the test
>> utility on the client shows that the first call to "utime()"
>> succeeds right away, the second call takes ~25s to complete. But
>> now, any consecutive runs of the utility finish with no more delay.
>>
>>
>> So can anyone confirm that with kernel 3.0+ the rpc.gssd daemon is
>> also required on the server side for correct operation?
>>
>> Has there been a change between kernel 2.6.32.59 and 3.0.x?
>>
>> Thus, is the init script of the nfsserver in SLES11SP3 indeed
>> missing to start rpc.gssd?
>
> It should be starting rpc.gssd to allow callbacks, yes.
>
> --b.
Ok, we will run rpc.gssd on the server. Thanks.
Could you please comment on having the nfs clients hang on utime() calls is to be expected when *not* running rpc.gssd? Or is this a problem that needs to be investigated?
Best regards,
J Brauchle
On 09/11/2013 12:11 AM, J. Bruce Fields wrote:
> On Tue, Sep 10, 2013 at 10:08:36PM +0000, Joschi Brauchle wrote:
>> Am 10.09.2013 um 23:55 schrieb "J. Bruce Fields" <[email protected]>:
>>
>>> On Tue, Sep 10, 2013 at 09:48:12PM +0000, Joschi Brauchle wrote:
>>>> Am 10.09.2013 um 22:35 schrieb "J. Bruce Fields" <[email protected]>:
>>>>
>>>>> On Tue, Sep 10, 2013 at 08:49:05PM +0200, Joschi Brauchle wrote:
>>>>>> Hello everyone,
>>>>>>
>>>>>> we are administrating an NFS high-availability cluster running on
>>>>>> SLES11SP1 with kernel 2.6.32.59. Just recently, one of the cluster
>>>>>> machines was updated to SLES11SP3 with kernel 3.0.82.
>>>>>>
>>>>>>
>>>>>> We are now experiencing severe hangs on NFS clients when the
>>>>>> SLES11SP3 server is running the NFS services. An strace on the
>>>>>> hanging processes on the client side show that is is waiting up to
>>>>>> 60+ seconds for a "utime()" call to complete.
>>>>>>
>>>>>>
>>>>>> The problem we see is matching the problem described in the thread
>>>>>> "v3.5 nfsd4 regression; utime sometimes takes 40+ seconds to
>>>>>> return". If the NFS server is running on SLES11SP3, the little test
>>>>>> program provided in this tread hangs at the "utime()" call for 60+
>>>>>> seconds. It hangs each time it is run! It finishes right away with 0
>>>>>> seconds delay is SLES11SP1 is providing NFS services, each time.
>>>>>>
>>>>>>
>>>>>> Now, in the serverside logfiles of SLES11SP3 we see these messages
>>>>>> (not so on SP1):
>>>>>> --------------
>>>>>> kernel: [99381.184976] RPC: AUTH_GSS upcall timed out.
>>>>>> kernel: [99381.184978] Please check user daemon is running.
>>>>>> --------------
>>>>>>
>>>>>> We have always been running the NFS server without rpc.gssd on the
>>>>>> server side, as the init script for the nfsserver also does not
>>>>>> start rpc.gssd.
>>>>>>
>>>>>>
>>>>>> Once we started rpc.gssd on the SLES11SP3 server, using the test
>>>>>> utility on the client shows that the first call to "utime()"
>>>>>> succeeds right away, the second call takes ~25s to complete. But
>>>>>> now, any consecutive runs of the utility finish with no more delay.
>>>>>>
>>>>>>
>>>>>> So can anyone confirm that with kernel 3.0+ the rpc.gssd daemon is
>>>>>> also required on the server side for correct operation?
>>>>>>
>>>>>> Has there been a change between kernel 2.6.32.59 and 3.0.x?
>>>>>>
>>>>>> Thus, is the init script of the nfsserver in SLES11SP3 indeed
>>>>>> missing to start rpc.gssd?
>>>>>
>>>>> It should be starting rpc.gssd to allow callbacks, yes.
>>>>>
>>>>> --b.
>>>>
>>>> Ok, we will run rpc.gssd on the server. Thanks.
>>>>
>>>> Could you please comment on having the nfs clients hang on utime() calls is to be expected when *not* running rpc.gssd? Or is this a problem that needs to be investigated?
>>>
>>> I think what happens is the utime call breaks a delegation, and the
>>> delay is because the lack of gssd prevents the server from calling back
>>> to the client to tell it that its delegation is broken, so the
>>> delegation has to time out.
>>>
>>> That said, the server does a null callback to the client to test whether
>>> callbacks are working before it gives out any delegations, so I'm
>>> surprised it wouldn't have noticed the broken callbacks then.
>>>
>>> --b.
>>
>> Is there any information I can provide to figure this out? At what time is the null callback sent to the client? Maybe I can tcpdump that sequence...
>
> It happens when the client sends a SETCLIENTID, which I think will be
> the first time it opens a file. Running "rpcdebug -m nfsd -s proc" on
> the server and then looking in the logs afterwards might also be
> enlightening.
>
> --b.
>
After three days of testing the NFS server *with* rpc.gssd running with
multiple NFS clients, we made the following observation:
The hangs on "utime()" calls have **not** disappeared by simply starting
rpc.gssd on the server. The problem persists!
I seems like
a) on machines that are already connected to the NFS server when
rpc.gssd is started, the hangs dissappear *mostly*. That is, running the
utime-test-program causes about 1 spurious hang every 10 minutes.
b) on machines that connect to the NFS server at a later time (rpc.gssd
already running on the server), the hangs seem appear every "utime()"
call.
The server emits spurious "RPC: AUTH_GSS upcall timed out. Please check
user daemon is running." messages, although rpc.gssd is running. This
may or may not be related, as this message may also be caused by clients
where the root user access NFS shared with a "host/<hostname>" credential.
The output of "rpcdebug -m nfsd -s proc" to pastebin.com. Get it with
pbget http://pastebin.com/N34r5kWE
The IP of the newly connected host is: 192.168.109.154 and its
SETCLIENTID call was logged. Unfortunately, this log was created while
*many* other NFS clients were connected, hence it may not be too useful.
I'd be very grateful for any help or instructions on debugging/fixing
this problem.
On Tue, Sep 10, 2013 at 10:08:36PM +0000, Joschi Brauchle wrote:
> Am 10.09.2013 um 23:55 schrieb "J. Bruce Fields" <[email protected]>:
>
> > On Tue, Sep 10, 2013 at 09:48:12PM +0000, Joschi Brauchle wrote:
> >> Am 10.09.2013 um 22:35 schrieb "J. Bruce Fields" <[email protected]>:
> >>
> >>> On Tue, Sep 10, 2013 at 08:49:05PM +0200, Joschi Brauchle wrote:
> >>>> Hello everyone,
> >>>>
> >>>> we are administrating an NFS high-availability cluster running on
> >>>> SLES11SP1 with kernel 2.6.32.59. Just recently, one of the cluster
> >>>> machines was updated to SLES11SP3 with kernel 3.0.82.
> >>>>
> >>>>
> >>>> We are now experiencing severe hangs on NFS clients when the
> >>>> SLES11SP3 server is running the NFS services. An strace on the
> >>>> hanging processes on the client side show that is is waiting up to
> >>>> 60+ seconds for a "utime()" call to complete.
> >>>>
> >>>>
> >>>> The problem we see is matching the problem described in the thread
> >>>> "v3.5 nfsd4 regression; utime sometimes takes 40+ seconds to
> >>>> return". If the NFS server is running on SLES11SP3, the little test
> >>>> program provided in this tread hangs at the "utime()" call for 60+
> >>>> seconds. It hangs each time it is run! It finishes right away with 0
> >>>> seconds delay is SLES11SP1 is providing NFS services, each time.
> >>>>
> >>>>
> >>>> Now, in the serverside logfiles of SLES11SP3 we see these messages
> >>>> (not so on SP1):
> >>>> --------------
> >>>> kernel: [99381.184976] RPC: AUTH_GSS upcall timed out.
> >>>> kernel: [99381.184978] Please check user daemon is running.
> >>>> --------------
> >>>>
> >>>> We have always been running the NFS server without rpc.gssd on the
> >>>> server side, as the init script for the nfsserver also does not
> >>>> start rpc.gssd.
> >>>>
> >>>>
> >>>> Once we started rpc.gssd on the SLES11SP3 server, using the test
> >>>> utility on the client shows that the first call to "utime()"
> >>>> succeeds right away, the second call takes ~25s to complete. But
> >>>> now, any consecutive runs of the utility finish with no more delay.
> >>>>
> >>>>
> >>>> So can anyone confirm that with kernel 3.0+ the rpc.gssd daemon is
> >>>> also required on the server side for correct operation?
> >>>>
> >>>> Has there been a change between kernel 2.6.32.59 and 3.0.x?
> >>>>
> >>>> Thus, is the init script of the nfsserver in SLES11SP3 indeed
> >>>> missing to start rpc.gssd?
> >>>
> >>> It should be starting rpc.gssd to allow callbacks, yes.
> >>>
> >>> --b.
> >>
> >> Ok, we will run rpc.gssd on the server. Thanks.
> >>
> >> Could you please comment on having the nfs clients hang on utime() calls is to be expected when *not* running rpc.gssd? Or is this a problem that needs to be investigated?
> >
> > I think what happens is the utime call breaks a delegation, and the
> > delay is because the lack of gssd prevents the server from calling back
> > to the client to tell it that its delegation is broken, so the
> > delegation has to time out.
> >
> > That said, the server does a null callback to the client to test whether
> > callbacks are working before it gives out any delegations, so I'm
> > surprised it wouldn't have noticed the broken callbacks then.
> >
> > --b.
>
> Is there any information I can provide to figure this out? At what time is the null callback sent to the client? Maybe I can tcpdump that sequence...
It happens when the client sends a SETCLIENTID, which I think will be
the first time it opens a file. Running "rpcdebug -m nfsd -s proc" on
the server and then looking in the logs afterwards might also be
enlightening.
--b.
On Tue, Sep 10, 2013 at 09:48:12PM +0000, Joschi Brauchle wrote:
> Am 10.09.2013 um 22:35 schrieb "J. Bruce Fields" <[email protected]>:
>
> > On Tue, Sep 10, 2013 at 08:49:05PM +0200, Joschi Brauchle wrote:
> >> Hello everyone,
> >>
> >> we are administrating an NFS high-availability cluster running on
> >> SLES11SP1 with kernel 2.6.32.59. Just recently, one of the cluster
> >> machines was updated to SLES11SP3 with kernel 3.0.82.
> >>
> >>
> >> We are now experiencing severe hangs on NFS clients when the
> >> SLES11SP3 server is running the NFS services. An strace on the
> >> hanging processes on the client side show that is is waiting up to
> >> 60+ seconds for a "utime()" call to complete.
> >>
> >>
> >> The problem we see is matching the problem described in the thread
> >> "v3.5 nfsd4 regression; utime sometimes takes 40+ seconds to
> >> return". If the NFS server is running on SLES11SP3, the little test
> >> program provided in this tread hangs at the "utime()" call for 60+
> >> seconds. It hangs each time it is run! It finishes right away with 0
> >> seconds delay is SLES11SP1 is providing NFS services, each time.
> >>
> >>
> >> Now, in the serverside logfiles of SLES11SP3 we see these messages
> >> (not so on SP1):
> >> --------------
> >> kernel: [99381.184976] RPC: AUTH_GSS upcall timed out.
> >> kernel: [99381.184978] Please check user daemon is running.
> >> --------------
> >>
> >> We have always been running the NFS server without rpc.gssd on the
> >> server side, as the init script for the nfsserver also does not
> >> start rpc.gssd.
> >>
> >>
> >> Once we started rpc.gssd on the SLES11SP3 server, using the test
> >> utility on the client shows that the first call to "utime()"
> >> succeeds right away, the second call takes ~25s to complete. But
> >> now, any consecutive runs of the utility finish with no more delay.
> >>
> >>
> >> So can anyone confirm that with kernel 3.0+ the rpc.gssd daemon is
> >> also required on the server side for correct operation?
> >>
> >> Has there been a change between kernel 2.6.32.59 and 3.0.x?
> >>
> >> Thus, is the init script of the nfsserver in SLES11SP3 indeed
> >> missing to start rpc.gssd?
> >
> > It should be starting rpc.gssd to allow callbacks, yes.
> >
> > --b.
>
> Ok, we will run rpc.gssd on the server. Thanks.
>
> Could you please comment on having the nfs clients hang on utime() calls is to be expected when *not* running rpc.gssd? Or is this a problem that needs to be investigated?
I think what happens is the utime call breaks a delegation, and the
delay is because the lack of gssd prevents the server from calling back
to the client to tell it that its delegation is broken, so the
delegation has to time out.
That said, the server does a null callback to the client to test whether
callbacks are working before it gives out any delegations, so I'm
surprised it wouldn't have noticed the broken callbacks then.
--b.
On Tue, Sep 10, 2013 at 08:49:05PM +0200, Joschi Brauchle wrote:
> Hello everyone,
>
> we are administrating an NFS high-availability cluster running on
> SLES11SP1 with kernel 2.6.32.59. Just recently, one of the cluster
> machines was updated to SLES11SP3 with kernel 3.0.82.
>
>
> We are now experiencing severe hangs on NFS clients when the
> SLES11SP3 server is running the NFS services. An strace on the
> hanging processes on the client side show that is is waiting up to
> 60+ seconds for a "utime()" call to complete.
>
>
> The problem we see is matching the problem described in the thread
> "v3.5 nfsd4 regression; utime sometimes takes 40+ seconds to
> return". If the NFS server is running on SLES11SP3, the little test
> program provided in this tread hangs at the "utime()" call for 60+
> seconds. It hangs each time it is run! It finishes right away with 0
> seconds delay is SLES11SP1 is providing NFS services, each time.
>
>
> Now, in the serverside logfiles of SLES11SP3 we see these messages
> (not so on SP1):
> --------------
> kernel: [99381.184976] RPC: AUTH_GSS upcall timed out.
> kernel: [99381.184978] Please check user daemon is running.
> --------------
>
> We have always been running the NFS server without rpc.gssd on the
> server side, as the init script for the nfsserver also does not
> start rpc.gssd.
>
>
> Once we started rpc.gssd on the SLES11SP3 server, using the test
> utility on the client shows that the first call to "utime()"
> succeeds right away, the second call takes ~25s to complete. But
> now, any consecutive runs of the utility finish with no more delay.
>
>
> So can anyone confirm that with kernel 3.0+ the rpc.gssd daemon is
> also required on the server side for correct operation?
>
> Has there been a change between kernel 2.6.32.59 and 3.0.x?
>
> Thus, is the init script of the nfsserver in SLES11SP3 indeed
> missing to start rpc.gssd?
It should be starting rpc.gssd to allow callbacks, yes.
--b.
Am 10.09.2013 um 23:55 schrieb "J. Bruce Fields" <[email protected]>:
> On Tue, Sep 10, 2013 at 09:48:12PM +0000, Joschi Brauchle wrote:
>> Am 10.09.2013 um 22:35 schrieb "J. Bruce Fields" <[email protected]>:
>>
>>> On Tue, Sep 10, 2013 at 08:49:05PM +0200, Joschi Brauchle wrote:
>>>> Hello everyone,
>>>>
>>>> we are administrating an NFS high-availability cluster running on
>>>> SLES11SP1 with kernel 2.6.32.59. Just recently, one of the cluster
>>>> machines was updated to SLES11SP3 with kernel 3.0.82.
>>>>
>>>>
>>>> We are now experiencing severe hangs on NFS clients when the
>>>> SLES11SP3 server is running the NFS services. An strace on the
>>>> hanging processes on the client side show that is is waiting up to
>>>> 60+ seconds for a "utime()" call to complete.
>>>>
>>>>
>>>> The problem we see is matching the problem described in the thread
>>>> "v3.5 nfsd4 regression; utime sometimes takes 40+ seconds to
>>>> return". If the NFS server is running on SLES11SP3, the little test
>>>> program provided in this tread hangs at the "utime()" call for 60+
>>>> seconds. It hangs each time it is run! It finishes right away with 0
>>>> seconds delay is SLES11SP1 is providing NFS services, each time.
>>>>
>>>>
>>>> Now, in the serverside logfiles of SLES11SP3 we see these messages
>>>> (not so on SP1):
>>>> --------------
>>>> kernel: [99381.184976] RPC: AUTH_GSS upcall timed out.
>>>> kernel: [99381.184978] Please check user daemon is running.
>>>> --------------
>>>>
>>>> We have always been running the NFS server without rpc.gssd on the
>>>> server side, as the init script for the nfsserver also does not
>>>> start rpc.gssd.
>>>>
>>>>
>>>> Once we started rpc.gssd on the SLES11SP3 server, using the test
>>>> utility on the client shows that the first call to "utime()"
>>>> succeeds right away, the second call takes ~25s to complete. But
>>>> now, any consecutive runs of the utility finish with no more delay.
>>>>
>>>>
>>>> So can anyone confirm that with kernel 3.0+ the rpc.gssd daemon is
>>>> also required on the server side for correct operation?
>>>>
>>>> Has there been a change between kernel 2.6.32.59 and 3.0.x?
>>>>
>>>> Thus, is the init script of the nfsserver in SLES11SP3 indeed
>>>> missing to start rpc.gssd?
>>>
>>> It should be starting rpc.gssd to allow callbacks, yes.
>>>
>>> --b.
>>
>> Ok, we will run rpc.gssd on the server. Thanks.
>>
>> Could you please comment on having the nfs clients hang on utime() calls is to be expected when *not* running rpc.gssd? Or is this a problem that needs to be investigated?
>
> I think what happens is the utime call breaks a delegation, and the
> delay is because the lack of gssd prevents the server from calling back
> to the client to tell it that its delegation is broken, so the
> delegation has to time out.
>
> That said, the server does a null callback to the client to test whether
> callbacks are working before it gives out any delegations, so I'm
> surprised it wouldn't have noticed the broken callbacks then.
>
> --b.
Is there any information I can provide to figure this out? At what time is the null callback sent to the client? Maybe I can tcpdump that sequence...
Best regards,
J Brauchle
On Fri, Sep 13, 2013 at 01:32:47PM +0200, Joschi Brauchle wrote:
> After three days of testing the NFS server *with* rpc.gssd running
> with multiple NFS clients, we made the following observation:
>
> The hangs on "utime()" calls have **not** disappeared by simply starting
> rpc.gssd on the server. The problem persists!
>
> I seems like
> a) on machines that are already connected to the NFS server when
> rpc.gssd is started, the hangs dissappear *mostly*. That is, running
> the utime-test-program causes about 1 spurious hang every 10
> minutes.
> b) on machines that connect to the NFS server at a later time
> (rpc.gssd already running on the server), the hangs seem appear
> every "utime()" call.
>
> The server emits spurious "RPC: AUTH_GSS upcall timed out. Please
> check user daemon is running." messages, although rpc.gssd is
> running. This may or may not be related, as this message may also be
> caused by clients where the root user access NFS shared with a
> "host/<hostname>" credential.
>
> The output of "rpcdebug -m nfsd -s proc" to pastebin.com. Get it with
> pbget http://pastebin.com/N34r5kWE
>
> The IP of the newly connected host is: 192.168.109.154 and its
> SETCLIENTID call was logged. Unfortunately, this log was created
> while *many* other NFS clients were connected, hence it may not be
> too useful.
>
> I'd be very grateful for any help or instructions on
> debugging/fixing this problem.
NFSv4.0 callbacks have just broken for a while, I think; I'll look into
it.
Meanwhile you should be able to work around this by disabling leases on
the server (so, "echo 0 >/proc/sys/fs/leases-enable" before starting
nfsd).
(Or if you're more daring and running a very recent upstream kernel,
switching to NFSv4.1 should work too.)
--b.