Kerberos authentication oddities

[Kevin Coffman]

Could you get a network trace and check what the server is returning
in the NULL call reply?  I'm guessing that it is GSS_S_NO_CONTEXT
(0x00080000).  If so, it is the same problem reported here:

http://linux-nfs.org/pipermail/nfsv4/2007-June/006237.html

If that is the case, it seems to happen "intermittently" and usually
goes away when changing things to try and debug it.

If you can reproduce it easily, that would be a great start at coming
up with a fix...

K.C.


2008/3/7 Lukas Hejtmanek <xhejtman at ics.muni.cz>:
> Hello,
>
>  I have a simple server with NFSv4 (nfs-utils 1.1.1). I use simple nsswitch for
>  uid-names mapping and I use kerberos.
>
>  However, I'm unable to mount it on client:
>  mount -t nfs4 -vvv -o sec=krb5,proto=tcp,port=2049,soft smaug1.ics.muni.cz:/
>  /mnt/nfs
>  mount: fstab path: "/etc/fstab"
>  mount: lock path:  "/etc/mtab~"
>  mount: temp path:  "/etc/mtab.tmp"
>  mount: spec:  "smaug1.ics.muni.cz:/"
>  mount: node:  "/mnt/nfs"
>  mount: types: "nfs4"
>  mount: opts:  "sec=krb5,proto=tcp,port=2049,soft"
>  mount: external mount: argv[0] = "/sbin/mount.nfs4"
>  mount: external mount: argv[1] = "smaug1.ics.muni.cz:/"
>  mount: external mount: argv[2] = "/mnt/nfs"
>  mount: external mount: argv[3] = "-v"
>  mount: external mount: argv[4] = "-o"
>  mount: external mount: argv[5] = "rw,sec=krb5,proto=tcp,port=2049,soft"
>  mount.nfs4: pinging: prog 100003 vers 4 prot tcp port 2049
>  mount.nfs4: Operation not permitted
>
>  From log messages, it looks OK:
>  Mar  7 18:41:18 anubis rpc.gssd[26735]: handling krb5 upcall
>  Mar  7 18:41:18 anubis rpc.gssd[26735]: getting credentials for client with
>  uid 0 for server smaug1.ics.muni.cz
>  Mar  7 18:41:18 anubis rpc.gssd[26735]: CC file 'krb5cc_0' being considered
>  Mar  7 18:41:18 anubis rpc.gssd[26735]: CC file 'krb5cc_0' matches owner check
>  and has mtime of 1204911510
>  Mar  7 18:41:18 anubis rpc.gssd[26735]: using FILE:/tmp/krb5cc_0 as
>  credentials cache for client with uid 0 for server smaug1.ics.muni.cz
>  Mar  7 18:41:18 anubis rpc.gssd[26735]: using environment variable to select
>  krb5 ccache FILE:/tmp/krb5cc_0
>  Mar  7 18:41:18 anubis rpc.gssd[26735]: creating context using fsuid
>  0 (save_uid 0)
>  Mar  7 18:41:18 anubis rpc.gssd[26735]: creating tcp client for server
>  smaug1.ics.muni.cz
>  Mar  7 18:41:18 anubis rpc.gssd[26735]: creating context with server
>  nfs at smaug1.ics.muni.cz
>  Mar  7 18:41:18 anubis rpc.gssd[26735]: DEBUG: serialize_krb5_ctx: lucid
>  version!
>  Mar  7 18:41:18 anubis rpc.gssd[26735]: prepare_krb5_rfc1964_buffer:
>  serializing keys with enctype 4 and length 8
>  Mar  7 18:41:18 anubis rpc.gssd[26735]: doing downcall
>  Mar  7 18:41:18 anubis rpc.gssd[26735]: destroying client clnt32
>  Mar  7 18:41:18 anubis rpc.gssd[26735]: destroying client clnt31
>
>  klist -e
>  Ticket cache: FILE:/tmp/krb5cc_0
>  Default principal: xhejtman at META
>
>  Valid starting     Expires            Service principal
>  03/07/08 18:38:25  03/08/08 18:38:23  krbtgt/META at META
>         Etype (skey, tkt): Triple DES cbc mode with HMAC/sha1, Triple DES cbc
>  mode with HMAC/sha1
>  03/07/08 18:38:30  03/08/08 18:38:23  krbtgt/ICS.MUNI.CZ at META
>         Etype (skey, tkt): DES cbc mode with CRC-32, DES cbc mode with CRC-32
>  03/07/08 18:38:30  03/08/08 18:38:23  nfs/smaug1.ics.muni.cz at ICS.MUNI.CZ
>         Etype (skey, tkt): DES cbc mode with CRC-32, DES cbc mode with CRC-32
>
>
>  Kerberos 4 ticket cache: /tmp/tkt0
>  klist: You have no tickets cached
>
>
>  On the server I have:
>  Mar  7 18:41:17 smaug1 rpc.svcgssd[10934]: leaving poll
>  Mar  7 18:41:17 smaug1 rpc.svcgssd[10934]: handling null request
>  Mar  7 18:41:18 smaug1 rpc.svcgssd[10934]: sname = xhejtman at META
>  Mar  7 18:41:18 smaug1 rpc.svcgssd[10934]: DEBUG: serialize_krb5_ctx: lucid
>  version!
>  Mar  7 18:41:18 smaug1 rpc.svcgssd[10934]: prepare_krb5_rfc1964_buffer:
>  serializing keys with
>   enctype 4 and length 8
>  Mar  7 18:41:18 smaug1 rpc.svcgssd[10934]: doing downcall
>  Mar  7 18:41:18 smaug1 rpc.svcgssd[10934]: mech: krb5, hndl len: 4, ctx len
>  85, timeout: 2147483647, uid: 12847, gid: 100, num aux grps: 1:
>  Mar  7 18:41:18 smaug1 rpc.svcgssd[10934]:   (   1) 100
>  Mar  7 18:41:18 smaug1 rpc.svcgssd[10934]: sending null reply
>  Mar  7 18:41:18 smaug1 rpc.svcgssd[10934]: writing message: \x
>  \x608201c206092a864886f7120102
>  0201006e8201b1308201ada003020105a10302010ea20703050020000000a381ee6181eb3081e8a003020105a10d1
>  b0b4943532e4d554e492e435aa2243022a003020101a11b30191b036e66731b12736d617567312e6963732e6d756e
>  692e637aa381ab3081a8a003020101a103020102a2819b04819831817997c0fbd31a05b52ff04611e43572e0ed690
>  6f878f61b55962ec2d8fb8a52104b50b65b19a502da8946a58216e3676602b543f8dfb2d45c5a1cac7a1b6abf1e82
>  4b1794d40cfca7c5e3824920e23829bc22df48856f993dabdefd470f760c11225341940028aa6168998512e133dd8
>  6f6742e16e17a3ee2b8110ff24fed9a68f5699e3ada53ea5c59701bca1dad9a4065462676d88ca481a63081a3a003
>  020101a2819b04819837c382e4af2df5277437c63f6a3dde0267c66426c44074c0e6d91100f06bc83c83f8098b438
>  792d897307ad43f6542ad36023747f64a30014aa848e8661367c6ca3a1f9abe44157aaf9e56f06e488bb64d47fef5
>  18f19933dac3491cc310d09bb8cbc034a3916f4e482ed75869192bb14016ae06d16b203354a422caf22de0101e7c8
>  8cd0b19b0e16c9b72547bbab655ba2ca2ebdf9c2cef 2147483647 0 0 \x02000000
>  \x607006092a864886f7120
>  10
>  Mar  7 18:41:18 smaug1 rpc.svcgssd[10934]: finished handling null request
>  Mar  7 18:41:18 smaug1 rpc.svcgssd[10934]: entering poll
>
>
>  Any ideas, what's wrong?
>
>  --
>  Lukáš Hejtmánek
>  _______________________________________________
>  NFSv4 mailing list
>  NFSv4 at linux-nfs.org
>  http://linux-nfs.org/cgi-bin/mailman/listinfo/nfsv4
>
>