Hi,
I am seeing "Permission denied" errors while running iozone on nfs
client with kerberos enabled. Digging further, I found there are a lot
of AUTH_REJECTEDCRED messages in nfs server log. NFS client tolerates
2 errors from server and tries to refresh the credentials. On the
third call it would throw an error to the application.
http://lxr.free-electrons.com/source/net/sunrpc/clnt.c#L2343
2395 switch ((n = ntohl(*p++))) {
2396 case RPC_AUTH_REJECTEDCRED:
2397 case RPC_AUTH_REJECTEDVERF:
2398 case RPCSEC_GSS_CREDPROBLEM:
2399 case RPCSEC_GSS_CTXPROBLEM:
2400 if (!task->tk_cred_retry)
2401 break;
2402 task->tk_cred_retry--;
2403 dprintk("RPC: %5u %s: retry stale creds\n",
2404 task->tk_pid, __func__);
2405 rpcauth_invalcred(task);
On the client I have seen this message twice :
Feb 26 10:27:01 atsqa6c71 kernel: RPC: 39431 call_status (status 20)
Feb 26 10:27:01 atsqa6c71 kernel: RPC: 39431 call_decode (status 20)
Feb 26 10:27:01 atsqa6c71 kernel: RPC: 39431 rpc_verify_header: retry
stale creds
Feb 26 10:27:01 atsqa6c71 kernel: RPC: 39431 invalidating RPCSEC_GSS
cred 880544ce4600
Feb 26 10:27:01 atsqa6c71 kernel: RPC: 39431 release request 8804062e7000
Feb 26 10:27:01 atsqa6c71 kernel: RPC: 39431 call_reserve (status 0)
Feb 26 10:27:01 atsqa6c71 kernel: RPC: 39431 failed to lock transport
8808723c5800
Feb 26 10:27:01 atsqa6c71 kernel: RPC: 39431 sleep_on(queue
"xprt_sending" time 25264836677)
Feb 26 10:27:01 atsqa6c71 kernel: RPC: 39431 added to queue
8808723c5990 "xprt_sending"
Feb 26 10:27:01 atsqa6c71 kernel: RPC: 39431 __rpc_wake_up_task (now
25264836722)
Feb 26 10:27:01 atsqa6c71 kernel: RPC: 39431 removed from queue
8808723c5990 "xprt_sending"
Feb 26 10:27:01 atsqa6c71 kernel: RPC: 39431 __rpc_execute flags=0x801
Feb 26 10:27:01 atsqa6c71 kernel: RPC: 39431 call_reserveresult (status -11)
Feb 26 10:27:01 atsqa6c71 kernel: RPC: 39431 call_retry_reserve (status 0)
Feb 26 10:27:01 atsqa6c71 kernel: RPC: 39431 reserved req
8806c2e01a00 xid 929383d1
Feb 26 10:27:01 atsqa6c71 kernel: RPC: 39431 call_reserveresult (status 0)
Feb 26 10:27:01 atsqa6c71 kernel: RPC: 39431 call_refresh (status 0)
Feb 26 10:27:01 atsqa6c71 kernel: RPC: 39431 refreshing RPCSEC_GSS
cred 88086f634240
On the third occurrence the filesystem OP failed :
Feb 26 10:28:25 atsqa6c71 kernel: RPC: 39431 __rpc_execute flags=0x801
Feb 26 10:28:25 atsqa6c71 kernel: RPC: 39431 call_status (status 20)
Feb 26 10:28:25 atsqa6c71 kernel: RPC: 39431 call_decode (status 20)
Feb 26 10:28:25 atsqa6c71 kernel: RPC: 39431 rpc_verify_header: call rejected 2
Feb 26 10:28:25 atsqa6c71 kernel: RPC: 39431 rpc_verify_header: call
failed with error -13
Feb 26 10:28:25 atsqa6c71 kernel: RPC: 39431 return 0, status -13
Say, the ticket has expired (within the renewable lifetime) and the
server did not find the ticket in the cache for the first time but the
second/third call shouldn't ideally fail when the credentials were
just refreshed through an upcall. Unavailability of the creds in the
cache/a failing svcauth_gss_accept_sec_context call could throw the
REJECTEDCRED error. Could you share some pointers on which is more
likely or if there is something else that could cause this issue.
Thanks,
Satya.
--
Check out the vibrant tech community on one of the world's most
engaging tech sites, SlashDot.org! http://sdm.link/slashdot
___
Nfs-ganesha-devel mailing list
Nfs-ganesha-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs-ganesha-devel