I've updated bug report with my analysis, would appreciate any of your
comments/suggestions for fixing the issue in a better way.

https://www.illumos.org/issues/4965

Issue analysis:

On Mac OS X, lockd uses UDP by default, and its UDP port is not specified
so the OS will assign any available port when the machine reboots.

In usr/src/uts/common/klm/nlm_rpc_handle.c, refresh_nlm_rpc() uses
nlm_null_rpc() to check if the client host's RPC binding is still fresh.
static int
refresh_nlm_rpc(struct nlm_host *hostp, nlm_rpc_t *rpcp)
{
...
{
enum clnt_stat stat;
stat = nlm_null_rpc(rpcp->nr_handle, rpcp->nr_vers);
if (NLM_STALE_CLNT(stat)) {
ret = ESTALE;
}
}
...
}

After a Mac host is rebooted and its lockd gets a different UDP port, and
then NLM on the server tries to send null_rpc to the old port, the issue
happens.

nlm_null_rpc() will return RPC_TIMEDOUT for UDP if the port is not
reachable but NLM_STALE_CLNT is defined as follows in
usr/src/uts/common/klm/nlm_rpc_handle.c:
#define NLM_STALE_CLNT(_status) \
((_status) == RPC_PROGUNAVAIL || \
(_status) == RPC_PROGVERSMISMATCH || \
(_status) == RPC_PROCUNAVAIL || \
(_status) == RPC_CANTCONNECT || \
(_status) == RPC_XPRTFAILED)

So refresh_nlm_rpc() never gets a chance to return ESTALE to its caller
nlm_host_get_rpc().

The following dtrace can show that nlm4_null_4() returns code
5(RPC_TIMEDOUT) after 150 seconds:
dtrace -n 'fbt::nlm4_null_4:entry {self->t=timestamp;}
fbt::nlm4_null_4:return /arg1 != 0 && self->t != 0/ { printf("ret = %d,
elapsed = %d, now = %Y\n", arg1, timestamp - self->t, walltimestamp);
self->t = 0;}'

The stack looks like:
              clnt_clts_kcallit:entry
              klmmod`nlm_clnt_call+0x73
              klmmod`nlm4_null_4+0x45
              klmmod`nlm_null_rpc+0x34
              klmmod`refresh_nlm_rpc+0x73
              klmmod`nlm_host_get_rpc+0xc6
              klmmod`nlm_do_lock+0x10d
              klmmod`nlm4_lock_msg_4_svc+0x53
              klmmod`nlm_dispatch+0xe6
              klmmod`nlm_prog_4+0x34
              rpcmod`svc_getreq+0x1c1
              rpcmod`svc_run+0x146
              rpcmod`svc_do_run+0x8e
              nfs`nfssys+0xf1
              unix`_sys_sysenter_post_swapgs+0x149

I made the following two changes and built a new image, the issue goes away.

--- a/usr/src/uts/common/klm/nlm_impl.c
+++ b/usr/src/uts/common/klm/nlm_impl.c
@@ -525,6 +525,12 @@ nlm_clnt_call(CLIENT *clnt, rpcproc_t procnum,
xdrproc_t xdr_args,
         */
        if (procnum >= NLM_TEST_RES && procnum <= NLM_GRANTED_RES)
                wait = nlm_rpctv_zero;
+       if (procnum == NLM_NULL) {
+               wait.tv_sec = 0;
+               wait.tv_usec = 25000;
+       }
+

--- a/usr/src/uts/common/klm/nlm_rpc_handle.c
+++ b/usr/src/uts/common/klm/nlm_rpc_handle.c
@@ -55,6 +55,7 @@
        (_status) == RPC_PROGVERSMISMATCH ||    \
        (_status) == RPC_PROCUNAVAIL ||         \
        (_status) == RPC_CANTCONNECT ||         \
+       (_status) == RPC_TIMEDOUT ||            \
        (_status) == RPC_XPRTFAILED)

Setting timeout value of NULL rpc to 25 milliseconds instead of the default
25 seconds can make nlm_null_rpc() returns RPC_TIMEDOUT after 1575
milliseconds when the UDP port is not reachable:
   1575 = 25 + 50 + 100 + 200 + 400 + 800 => 5 retries



-------------------------------------------
smartos-discuss
Archives: https://www.listbox.com/member/archive/184463/=now
RSS Feed: https://www.listbox.com/member/archive/rss/184463/25769125-55cfbc00
Modify Your Subscription: 
https://www.listbox.com/member/?member_id=25769125&id_secret=25769125-7688e9fb
Powered by Listbox: http://www.listbox.com

Reply via email to