[Freeipa-users] secure NFSv4 failure after IPA server upgrade

[Thomas Sailer]

After upgrading FreeIPA from FC14/FreeIPAv1 to FC16/FreeIPAv2, secure 
NFSv4 mounts do not work anymore. V2 is basically a reinstalled FreeIPA 
server with user data migrated from v1, and host keys etc. recreated.

I get the following when trying to mount:
# mount -t nfs4 -o soft,intr,rsize=8192,wsize=8192,rw,sec=krb5p 
server.xxxxx.com:/yyyyy z
mount.nfs4: access denied by server while mounting server.xxxxx.com:/yyyyy

On the client, rpc.gssd reports:
Warning: rpcsec_gss library does not support setting debug level
beginning poll
dir_notify_handler: sig 37 si 0x7fff5f5f5d30 data 0x7fff5f5f5c00
dir_notify_handler: sig 37 si 0x7fff5f5f1570 data 0x7fff5f5f1440
dir_notify_handler: sig 37 si 0x7fff5f5f0df0 data 0x7fff5f5f0cc0
handling gssd upcall (/var/lib/nfs/rpc_pipefs/nfs/clnt3a)
handle_gssd_upcall: 'mech=krb5 uid=0 enctypes=18,17,16,23,3,1,2 '
handling krb5 upcall (/var/lib/nfs/rpc_pipefs/nfs/clnt3a)
process_krb5_upcall: service is '<null>'
Full hostname for 'server.xxxxx.com' is 'server.xxxxx.com'
Full hostname for 'client.xxxxx.com' is 'client.xxxxx.com'
No key table entry found for CLIENT.XXXXX.COM$@XXXXX.COM while getting 
keytab entry for 'CLIENT.XXXXX.COM$@XXXXX.COM'
No key table entry found for root/client.xxxxx.com at XXXXX.COM while 
getting keytab entry for 'root/client.xxxxx.com at XXXXX.COM'
Success getting keytab entry for 'nfs/client.xxxxx.com at XXXXX.COM'
Successfully obtained machine credentials for principal 
'nfs/client.xxxxx.com at XXXXX.COM' stored in ccache 
'FILE:/tmp/krb5cc_machine_XXXXX.COM'
INFO: Credentials in CC 'FILE:/tmp/krb5cc_machine_XXXXX.COM' are good 
until 1321556514
using FILE:/tmp/krb5cc_machine_XXXXX.COM as credentials cache for 
machine creds
using environment variable to select krb5 ccache 
FILE:/tmp/krb5cc_machine_XXXXX.COM
creating context using fsuid 0 (save_uid 0)
creating tcp client for server server.xxxxx.com
DEBUG: port already set to 2049
creating context with server nfs at server.xxxxx.com
WARNING: Failed to create krb5 context for user with uid 0 for server 
server.xxxxx.com
WARNING: Failed to create machine krb5 context with credentials cache 
FILE:/tmp/krb5cc_machine_XXXXX.COM for server server.xxxxx.com
WARNING: Machine cache is prematurely expired or corrupted trying to 
recreate cache for server server.xxxxx.com
Full hostname for 'server.xxxxx.com' is 'server.xxxxx.com'
Full hostname for 'client.xxxxx.com' is 'client.xxxxx.com'
No key table entry found for CLIENT.XXXXX.COM$@XXXXX.COM while getting 
keytab entry for 'CLIENT.XXXXX.COM$@XXXXX.COM'
No key table entry found for root/client.xxxxx.com at XXXXX.COM while 
getting keytab entry for 'root/client.xxxxx.com at XXXXX.COM'
Success getting keytab entry for 'nfs/client.xxxxx.com at XXXXX.COM'
INFO: Credentials in CC 'FILE:/tmp/krb5cc_machine_XXXXX.COM' are good 
until 1321556514
INFO: Credentials in CC 'FILE:/tmp/krb5cc_machine_XXXXX.COM' are good 
until 1321556514
using FILE:/tmp/krb5cc_machine_XXXXX.COM as credentials cache for 
machine creds
using environment variable to select krb5 ccache 
FILE:/tmp/krb5cc_machine_XXXXX.COM
creating context using fsuid 0 (save_uid 0)
creating tcp client for server server.xxxxx.com
DEBUG: port already set to 2049
creating context with server nfs at server.xxxxx.com
WARNING: Failed to create krb5 context for user with uid 0 for server 
server.xxxxx.com
WARNING: Failed to create machine krb5 context with credentials cache 
FILE:/tmp/krb5cc_machine_XXXXX.COM for server server.xxxxx.com
WARNING: Failed to create machine krb5 context with any credentials 
cache for server server.xxxxx.com
doing error downcall
dir_notify_handler: sig 37 si 0x7fff5f5f5d30 data 0x7fff5f5f5c00
dir_notify_handler: sig 37 si 0x7fff5f5f5d30 data 0x7fff5f5f5c00
dir_notify_handler: sig 37 si 0x7fff5f5f5d30 data 0x7fff5f5f5c00
dir_notify_handler: sig 37 si 0x7fff5f5f5d30 data 0x7fff5f5f5c00
dir_notify_handler: sig 37 si 0x7fff5f5f5d30 data 0x7fff5f5f5c00
dir_notify_handler: sig 37 si 0x7fff5f5f5d30 data 0x7fff5f5f5c00
dir_notify_handler: sig 37 si 0x7fff5f5f5d30 data 0x7fff5f5f5c00
destroying client /var/lib/nfs/rpc_pipefs/nfs/clnt3b
destroying client /var/lib/nfs/rpc_pipefs/nfs/clnt3a

And on the server, rpc.svcgssd reports:
leaving poll
handling null request
svcgssd_limit_krb5_enctypes: Calling gss_set_allowable_enctypes with 7 
enctypes from defaults
sname = nfs/client.xxxxx.com at XXXXX.COM
DEBUG: serialize_krb5_ctx: lucid version!
prepare_krb5_rfc4121_buffer: protocol 1
prepare_krb5_rfc4121_buffer: serializing key with enctype 18 and size 32
doing downcall
mech: krb5, hndl len: 4, ctx len 52, timeout: 1321556514 (86400 from 
now), clnt: nfs at client.xxxxx.com, uid: -1, gid: -1, num aux grps: 0:
sending null reply
writing message: \x \x6082....\x6081....
entering poll
leaving poll
handling null request
svcgssd_limit_krb5_enctypes: Calling gss_set_allowable_enctypes with 7 
enctypes from defaults
sname = nfs/client.xxxxx.com at XXXXX.COM
DEBUG: serialize_krb5_ctx: lucid version!
prepare_krb5_rfc4121_buffer: protocol 1
prepare_krb5_rfc4121_buffer: serializing key with enctype 18 and size 32
doing downcall
mech: krb5, hndl len: 4, ctx len 52, timeout: 1321556514 (86400 from 
now), clnt: nfs at client.xxxxx.com, uid: -1, gid: -1, num aux grps: 0:
sending null reply
writing message: \x \x6082.... 1321470174 0 0 \x02000000 \x6081....
finished handling null request
entering poll

Does anyone have an idea what went wrong? The client is also FC16, and 
it worked against the FC14/FreeIPAv1 server.

Tom