RPC: AUTH_GSS upcall timed out -- out of ideas

[Andri]

Kevin Coffman wrote:
> On 10/14/06, Andri <aoeuid at gmail.com> wrote:
>> Kevin Coffman wrote:
>> > On 10/14/06, Andri <aoeuid at gmail.com> wrote:
>> >> Got a bit clearer view now thanks to this description:
>> >> http://www.citi.umich.edu/projects/nfsv4/gssd/
>> >
>> > So on the client, mount should call into the kernel.  The kernel will
>> > find it needs a gss context and do an upcall to gssd.  It is claiming
>> > that there is no gssd running to handle the upcall request
>> >
>> >>
>> >> # tail -2 /var/log/messages
>> >> Oct 14 14:24:00 client RPC: AUTH_GSS upcall timed out.
>> >> Oct 14 14:24:00 client Please check user daemon is running!
>> >>
>> >
>> > The lack of any output from gssd (to handle an upcall) seems to
>> > reinforce this.
>> >
>> >> # rpc.gssd -vvvf
>> >> Using keytab file '/etc/krb5.keytab'
>> >> Processing keytab entry for principal 'host/client.realm at REALM'
>> >> We will NOT use this entry (host/client.realm at REALM)
>> >> Processing keytab entry for principal 'nfs/client.realm at REALM'
>> >> We will use this entry (nfs/client.realm at REALM)
>> >> Using (machine) credentials cache: 'FILE:/tmp/krb5cc_machine_REALM'
>> >> WARNING: gssd_obtain_kernel_krb5_info: Unable to open
>> >> '/var/lib/nfs/rpc_pipefs/nfs/krb5_info'. Unable to determine Kerberos
>> >> encryption types supported by the kernel; using defaults (1,3,2).
>> >>
>> >
>> > I'm pretty sure you'd have seen an error message, but just be clear:
>> > do you have the pipefs mounted?
>> Yes, of course :)
>>
>> > % grep pipefs /etc/fstab
>> > rpc_pipefs      /var/lib/nfs/rpc_pipefs rpc_pipefs      defaults 0 0
>> > % mount
>> > ...
>> > rpc_pipefs on /var/lib/nfs/rpc_pipefs type rpc_pipefs (rw)
>> >
>> I mounted it manually, but just to be sure I tried again with the fstab
>> approach -- nothing seemed to have changed.
>>
>> # mount | grep pipe
>> rpc_pipefs on /var/lib/nfs/rpc_pipefs type rpc_pipefs (rw)
> 
> Try turning on debugging in the kernel code on the client:
> 
> # echo 16 >/proc/sys/sunrpc/rpc_debug
> 

That indeed let the bowels run -- all of the output after starting mount:
Oct 14 21:06:37 client RPC: creating UNIX authenticator for client ca330c00
Oct 14 21:06:37 client RPC: 55632 looking up UNIX cred
Oct 14 21:06:37 client RPC: gc'ing RPC credentials for auth c04bad80
Oct 14 21:06:37 client RPC:      allocating UNIX cred for uid 0 gid 0
Oct 14 21:06:37 client RPC: 55632 marshaling UNIX cred d45708a0
Oct 14 21:06:37 client RPC: 55632 using AUTH_UNIX cred d45708a0 to wrap
rpc data
Oct 14 21:06:37 client RPC: 55632 validating UNIX cred d45708a0
Oct 14 21:06:37 client RPC: 55632 using AUTH_UNIX cred d45708a0 to
unwrap rpc data
Oct 14 21:06:37 client RPC: 55632 releasing UNIX cred d45708a0
Oct 14 21:06:37 client RPC: destroying UNIX authenticator c04bad80
Oct 14 21:06:37 client RPC: creating UNIX authenticator for client ca330c00
Oct 14 21:06:37 client RPC: 55633 looking up UNIX cred
Oct 14 21:06:37 client RPC:      allocating UNIX cred for uid 0 gid 0
Oct 14 21:06:37 client RPC: 55633 marshaling UNIX cred c71468c0
Oct 14 21:06:37 client RPC: 55633 using AUTH_UNIX cred c71468c0 to wrap
rpc data
Oct 14 21:06:37 client RPC: 55633 validating UNIX cred c71468c0
Oct 14 21:06:37 client RPC: 55633 using AUTH_UNIX cred c71468c0 to
unwrap rpc data
Oct 14 21:06:37 client RPC: 55633 releasing UNIX cred c71468c0
Oct 14 21:06:37 client RPC: destroying UNIX authenticator c04bad80
Oct 14 21:06:37 client RPC:      creating GSS authenticator for client
c90ad800
Oct 14 21:06:37 client RPC: 55634 holding RPCSEC_GSS cred c04baca0
Oct 14 21:06:37 client RPC: creating UNIX authenticator for client c3ddf600
Oct 14 21:06:37 client RPC: 55635 looking up UNIX cred
Oct 14 21:06:37 client RPC:      allocating UNIX cred for uid 0 gid 0
Oct 14 21:06:37 client RPC: 55635 marshaling UNIX cred c277cee0
Oct 14 21:06:37 client RPC: 55635 using AUTH_UNIX cred c277cee0 to wrap
rpc data
Oct 14 21:06:37 client RPC: 55635 validating UNIX cred c277cee0
Oct 14 21:06:37 client RPC: 55635 using AUTH_UNIX cred c277cee0 to
unwrap rpc data
Oct 14 21:06:37 client RPC: 55635 releasing UNIX cred c277cee0
Oct 14 21:06:37 client RPC: destroying UNIX authenticator c04bad80
Oct 14 21:06:37 client RPC: 55634 marshaling RPCSEC_GSS cred c04baca0
Oct 14 21:06:37 client RPC: 55634 using AUTH_NULL cred c04baca0 to wrap
rpc data
Oct 14 21:06:37 client RPC: 55634 validating RPCSEC_GSS cred c04baca0
Oct 14 21:06:37 client RPC: 55634 using AUTH_NULL cred c04baca0 to
unwrap rpc data
Oct 14 21:06:37 client RPC: 55634 releasing RPCSEC_GSS cred c04baca0
Oct 14 21:06:37 client RPC: 55636 looking up RPCSEC_GSS cred
Oct 14 21:06:37 client RPC:      gss_create_cred for uid 0, flavor 390003
Oct 14 21:06:37 client RPC: gss_upcall for uid 0
Oct 14 21:06:37 client RPC:      gss_find_upcall found nothing
Oct 14 21:07:07 client RPC:      gss_pipe_destroy_msg releasing msg c277cee0
Oct 14 21:07:07 client RPC: AUTH_GSS upcall timed out.
Oct 14 21:07:07 client Please check user daemon is running!
Oct 14 21:07:07 client RPC: gss_create_upcall for uid 0 result -110
Oct 14 21:07:07 client RPC:      destroying GSS authenticator c71468c0
flavor 390003
Oct 14 21:07:07 client RPC:      gss_destroy_cred

>From the upcall for uid 0 I thought perhaps I'd try adding
root/client.realm at REALM to the principal list, and to the client's
keytab, but that didn't change anything on the 'failing mount' side.

# kinit -k nfs/client.realm,
# kinit -k host/client.realm
and
# kinit -k root/client.realm
all seem to work, at least klist gives:
10/14/06 21:17:31  10/15/06 07:17:31  krbtgt/REALM at REALM
        renew until 10/15/06 21:17:31


Thanks in advance again!


Andri