Hi
It appears that the RPCSEC_GSS Kerberos calls were successful, but
that the Kerberos principal to id mapping failed.
> Feb 10 14:45:17 tm rpc.svcgssd[1335]: sname = root/<client-fqdn>@<MYREALM>
> Feb 10 14:45:17 tm rpc.svcgssd[1335]: libnfsidmap: using (default) domain: cs.uni-potsdam.de
> Feb 10 14:45:17 tm rpc.svcgssd[1335]: libnfsidmap: loaded plugin /usr/lib/libnfsidmap/nsswitch.so for method nsswitch
> Feb 10 14:45:17 tm rpc.svcgssd[1335]: nss_gss_princ_to_ids: Local-Realm '<MYREALM>': NOT FOUND
What kernel is the server running?
What nfs-utils version is the server using?
What libnfsidmap version is the server using?
Thanks
-->Andy
On Fri, Feb 10, 2012 at 9:45 AM, <whats_up@xxxxxxx> wrote:
>
> Hi,
>
> I want to setup a file server with NFS4+Kerberos and Debian squeeze for
> clients running Ubuntu 11.10.
>
> What is already working:
> 1) Mount NFS4 on client without krb5 option works. Users are able to
> access files and uids/gids are correct. 2) KDC works. Access from
> client, get tickets, user authentication/change password through pam is
> ok.
>
> Now I want to mount with sec=krb5 but this time the command hangs and
> does not return to shell. See also logs below.
>
> Any hints to fix the issue or to get more helpful debug information are
> welcome.
>
> regards
> knut
>
>
>
>
> === server status ===
>
> Debian Linux squeeze
>
> # uname -a
> Linux tm 2.6.32-5-686 #1 SMP Mon Jan 16 16:04:25 UTC 2012 i686 GNU/Linux
>
> # cat /etc/exports
> /srv *(rw,sync,no_subtree_check,fsid=0,crossmnt)
> /srv/opt *(sec=sys:krb5,rw,sync,no_subtree_check)
>
> # ps -ef|grep -e rpc -e portmap -e nfs
> daemon 1019 1 0 10:26 ? 00:00:00 /sbin/portmap
> root 1043 2 0 10:26 ? 00:00:00 [rpciod/0]
> root 1044 2 0 10:26 ? 00:00:00 [rpciod/1]
> root 1055 2 0 10:26 ? 00:00:00 [nfsiod]
> root 1079 1 0 10:26 ? 00:00:00 /usr/sbin/rpc.idmapd -vvv
> root 1083 1 0 10:26 ? 00:00:00 /usr/sbin/rpc.gssd -vvv
> root 1309 2 0 10:26 ? 00:00:00 [nfsd4]
> root 1310 2 0 10:26 ? 00:00:00 [nfsd]
> ...
> root 1336 1 0 10:26 ? 00:00:00 /usr/sbin/rpc.svcgssd -vvv
> root 1338 1 0 10:26 ? 00:00:00 /usr/sbin/rpc.mountd --manage-gids
>
> # rpcdebug -m nfsd -s all
>
>
> === client status ===
>
> Ubuntu Linux 10.11
>
> # uname -a
> Linux orest 3.0.0-15-generic #26-Ubuntu SMP Fri Jan 20 15:59:53 UTC 2012 i686 i686 i386 GNU/Linux
>
> # ps -ef |grep rpc
> root 702 1 0 13:16 ? 00:00:00 rpcbind -w
> root 712 2 0 13:16 ? 00:00:00 [rpciod]
> root 805 1 0 13:16 ? 00:00:00 rpc.gssd -vvv
> root 890 1 0 13:16 ? 00:00:00 rpc.idmapd -vvv
>
>
> === client log ===
>
> # mount -t nfs4 <server-fqdn>:/opt /opt
> # umount /opt
>
> # mount -t nfs4 -osec=krb5 <server-fqdn>:/opt /opt
> Feb 10 14:45:17 orest rpc.gssd[883]: dir_notify_handler: sig 37 si 0xbfe7584c data 0xbfe758cc
> Feb 10 14:45:17 orest rpc.idmapd[728]: New client: 0
> Feb 10 14:45:17 orest rpc.gssd[883]: dir_notify_handler: sig 37 si 0xbfe7102c data 0xbfe710ac
> Feb 10 14:45:17 orest rpc.idmapd[728]: Opened /var/lib/nfs/rpc_pipefs/nfs/clnt0/idmap
> Feb 10 14:45:17 orest rpc.gssd[883]: dir_notify_handler: sig 37 si 0xbfe7102c data 0xbfe710ac
> Feb 10 14:45:17 orest rpc.idmapd[728]: New client: 1
> Feb 10 14:45:17 orest rpc.gssd[883]: handling gssd upcall (/var/lib/nfs/rpc_pipefs/nfs/clnt0)
> Feb 10 14:45:17 orest rpc.gssd[883]: handle_gssd_upcall: 'mech=krb5 uid=0 enctypes=18,17,16,23,3,1,2 '
> Feb 10 14:45:17 orest rpc.gssd[883]: handling krb5 upcall (/var/lib/nfs/rpc_pipefs/nfs/clnt0)
> Feb 10 14:45:17 orest rpc.gssd[883]: process_krb5_upcall: service is '<null>'
> Feb 10 14:45:17 orest rpc.gssd[883]: Full hostname for '<server-fqdn>' is '<server-fqdn>'
> Feb 10 14:45:17 orest rpc.gssd[883]: Full hostname for '<client-fqdn>' is '<client-fqdn>'
> Feb 10 14:45:17 orest rpc.gssd[883]: No key table entry found for <CLIENT-HOSTNAME>$@<MYREALM> while getting keytab entry for '<CLIENT-HOSTNAME>$@<MYREALM>'
> Feb 10 14:45:17 orest rpc.gssd[883]: Success getting keytab entry for 'root/<client-fqdn>@<MYREALM>'
> Feb 10 14:45:17 orest rpc.gssd[883]: Successfully obtained machine credentials for principal 'root/<client-fqdn>@<MYREALM>' stored in ccache 'FILE:/tmp/krb5cc_machine_<MYREALM>'
> Feb 10 14:45:17 orest rpc.gssd[883]: INFO: Credentials in CC 'FILE:/tmp/krb5cc_machine_<MYREALM>' are good until 1328967917
> Feb 10 14:45:17 orest rpc.gssd[883]: using FILE:/tmp/krb5cc_machine_<MYREALM> as credentials cache for machine creds
> Feb 10 14:45:17 orest rpc.gssd[883]: using environment variable to select krb5 ccache FILE:/tmp/krb5cc_machine_<MYREALM>
> Feb 10 14:45:17 orest rpc.gssd[883]: creating context using fsuid 0 (save_uid 0)
> Feb 10 14:45:17 orest rpc.gssd[883]: creating tcp client for server <server-fqdn>
> Feb 10 14:45:17 orest rpc.gssd[883]: DEBUG: port already set to 2049
> Feb 10 14:45:17 orest rpc.gssd[883]: creating context with server nfs@<server-fqdn>
> Feb 10 14:45:17 orest rpc.gssd[883]: DEBUG: serialize_krb5_ctx: lucid version!
> Feb 10 14:45:17 orest rpc.gssd[883]: prepare_krb5_rfc1964_buffer: serializing keys with enctype 4 and length 8
> Feb 10 14:45:17 orest rpc.gssd[883]: doing downcall
>
> (waiting...)
>
> Feb 10 14:48:17 orest kernel: [ 249.312058] nfs: server <server-fqdn> not responding, still trying
>
> (press Ctrl-C, >10 min later)
>
> Feb 10 14:59:40 orest rpc.gssd[883]: dir_notify_handler: sig 37 si 0xbfe7584c data 0xbfe758cc
> Feb 10 14:59:40 orest rpc.gssd[883]: dir_notify_handler: sig 37 si 0xbfe7584c data 0xbfe758cc
> Feb 10 14:59:40 orest rpc.gssd[883]: destroying client /var/lib/nfs/rpc_pipefs/nfs/clnt1
> Feb 10 14:59:40 orest rpc.idmapd[728]: Stale client: 1
> Feb 10 14:59:40 orest rpc.idmapd[728]: #011-> closed /var/lib/nfs/rpc_pipefs/nfs/clnt1/idmap
> Feb 10 14:59:40 orest rpc.gssd[883]: dir_notify_handler: sig 37 si 0xbfe7584c data 0xbfe758cc
> Feb 10 14:59:40 rpc.gssd[883]: last message repeated 4 times
> Feb 10 14:59:40 orest rpc.idmapd[728]: Stale client: 0
> Feb 10 14:59:40 orest rpc.idmapd[728]: #011-> closed /var/lib/nfs/rpc_pipefs/nfs/clnt0/idmap
> Feb 10 14:59:40 orest rpc.gssd[883]: destroying client /var/lib/nfs/rpc_pipefs/nfs/clnt0
>
>
>
> === server log ===
>
> The following messages appeared while initiating mount command on client:
>
> ==> auth.log <==
> Feb 10 14:45:17 tm krb5kdc[1429]: AS_REQ (7 etypes {18 17 16 23 1 3 2}) <client-IP>: NEEDED_PREAUTH: root/<client-fqdn>@<MYREALM> for krbtgt/<MYREALM>@<MYREALM>, Additional pre-authentication required
> Feb 10 14:45:17 tm krb5kdc[1429]: AS_REQ (7 etypes {18 17 16 23 1 3 2}) <client-IP>: ISSUE: authtime 1328881517, etypes {rep=1 tkt=18 ses=18}, root/<client-fqdn>@<MYREALM> for krbtgt/<MYREALM>@<MYREALM>
> Feb 10 14:45:17 tm krb5kdc[1429]: TGS_REQ (7 etypes {18 17 16 23 1 3 2}) <client-IP>: ISSUE: authtime 1328881517, etypes {rep=18 tkt=1 ses=1}, root/<client-fqdn>@<MYREALM> for nfs/<server-fqdn>@<MYREALM>
>
> ==> syslog <==
> Feb 10 14:45:17 tm rpc.svcgssd[1335]: leaving poll
> Feb 10 14:45:17 tm rpc.svcgssd[1335]: handling null request
> Feb 10 14:45:17 tm rpc.svcgssd[1335]: sname = root/<client-fqdn>@<MYREALM>
> Feb 10 14:45:17 tm rpc.svcgssd[1335]: libnfsidmap: using (default) domain: cs.uni-potsdam.de
> Feb 10 14:45:17 tm rpc.svcgssd[1335]: libnfsidmap: loaded plugin /usr/lib/libnfsidmap/nsswitch.so for method nsswitch
> Feb 10 14:45:17 tm rpc.svcgssd[1335]: nss_gss_princ_to_ids: Local-Realm '<MYREALM>': NOT FOUND
> Feb 10 14:45:17 tm rpc.svcgssd[1335]: DEBUG: serialize_krb5_ctx: lucid version!
> Feb 10 14:45:17 tm rpc.svcgssd[1335]: prepare_krb5_rfc1964_buffer: serializing keys with enctype 4 and length 8
> Feb 10 14:45:17 tm rpc.svcgssd[1335]: doing downcall
> Feb 10 14:45:17 tm rpc.svcgssd[1335]: mech: krb5, hndl len: 4, ctx len 85, timeout: 1328967917 (86400 from now), clnt: root@<client-fqdn>, uid: -1, gid: -1, num aux grps: 0:
> Feb 10 14:45:17 tm rpc.svcgssd[1335]: sending null reply
> Feb 10 14:45:17 tm rpc.svcgssd[1335]: writing message: \x \x..<lots of digits> 1328881577 0 0 \x01000000 \x607006092a864886f71201020202006f61305fa003020105a10302010fa2533051a003020101a24a0448d85b3308847004f703039fd5f315f81fcbb287c6a53821eb2ea8660169c687bbb0f1d7fbdecb9016284f3adf11b122949b98488862d956d352c6c14e6fd2beb565ba1de7afc99d1c
> Feb 10 14:45:17 tm rpc.svcgssd[1335]: finished handling null request
> Feb 10 14:45:17 tm rpc.svcgssd[1335]: entering poll
>
> (waiting...)
>
> --
> To unsubscribe from this list: send the line "unsubscribe linux-nfs" in
> the body of a message to majordomo@xxxxxxxxxxxxxxx
> More majordomo info at http://vger.kernel.org/majordomo-info.html
--
To unsubscribe from this list: send the line "unsubscribe linux-nfs" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
