nfs4 and kerberos: Wrong principal in request

ubuntu kerberos nfs4 heimdal

11,549

Solution 1

I've found the solution:

Looking at an strace of the rpc.svcgssd daemon, I saw that the last file opened before the error ways the /etc/krb5.keytab.

The keytab on the server was generated using kadmin with a kinit of "kadmin/admin".

A kinit -k -t /etc/krb5.keytab nfs/SERVER.example.com@REALM on the SERVER resulted in a invalid password errror. So i deleted the keytab and generated a new one using kadmin -l. There might be a problem with the keytab of my kadmin/admin user that resulted in a corrupt keytab. I haven't investigaed the problem yet.

After I created a new keytab, the nfs4+krb5 mount succeeded.

Thank your for your answers, they helped a lot in narrowing the problem down.

So for anyone encountering a similiar problem:

Try to kinit the service tickets on every invovled host using kinit -k -t /etc/krb5.keytab nfs/SERVER.example.com@REALM
Do a strace -p $(pidof rpc.svcgssd) -s4096 -e trace=open,close,read,write and check what is happening before the error occurs.
From all I have read, the "Wrong Principal" error usually occurs if the machines have a mapping to 127.0.0.1 for their hostname.

Solution 2

People dealing with problems like this, usually do:

DNS names and FQDN of your hosts must be lowercase, even if your DNS supports Uppercase in FQDN.
You should have a principal named like your machine name, in example: [email protected], and add to keytab accordingly (all UPERCASE and ending with $)
You should have principals host/your-machine.your.domain.name and nfs/your-machine.your.domain.name, and add this principal to keytab accordingly.
Your /etc/hosts must not have uppercases names, and FQDN should be firsts than short name if any.

Solution 3

You are using a syntax marked as DEPRECATED in the exports(5) manpage:

RPCSEC_GSS security
   You may use the special strings "gss/krb5", "gss/krb5i", or "gss/krb5p" to restrict
   access to clients using rpcsec_gss security.  However, this syntax is deprecated; on
   linux kernels  since  2.6.23,  you  should instead use the "sec=" export option:

   sec=   The  sec=  option,  followed  by a colon-delimited list of security flavors, restricts the export to clients using those flavors.  Available security flavors include sys (the default--no cryptographic secu‐
          rity), krb5 (authentication only), krb5i (integrity protection), and krb5p (privacy protection).  For the purposes of security flavor negotiation, order counts: preferred flavors  should  be  listed  first.
          The  order  of  the  sec=  option  with respect to the other options does not matter, unless you want some options to be enforced differently depending on flavor.  In that case you may include multiple sec=
          options, and following options will be enforced only for access using flavors listed in the immediately preceding sec= option.  The only options  that  are  permitted  to  vary  in  this  way  are  ro,  rw,
          no_root_squash, root_squash, and all_squash.

So your exports should be:

/srv      XXX.XXX.209.0/24(fsid=0,rw,no_subtree_check,root_squash,async,sec=krb5)
/srv/home XXX.XXX.209.0/24(rw,no_subtree_check,root_squash,async,sec=krb5)

It is important that both the fsid=0 and the exported resource have the correct security configuration. Choose the appropriate krb5/krb5i/krb5p for your setup.

The error "Wrong principal in request" can be caused by wrong name resolution. If you are using local resolution, inspect your /etc/hosts file.

11,549

cebalrai

Updated on September 18, 2022

Comments

cebalrai almost 2 years

My client/servers are both running Ubuntu 14.04 and kerberos user authentication works as intended. regular nfs4 mounts also work fine. All machines are running heimdal libraries.

I haven't been able to get kerberized nfs4 working though.

When mounting a share, I get the following entries in the logs:

NFS4 Server:

  Jun 22 11:25:13 SERVER rpc.svcgssd[7349]: leaving poll
  Jun 22 11:25:13 SERVER rpc.svcgssd[7349]: handling null request
  Jun 22 11:25:13 SERVER rpc.svcgssd[7349]: svcgssd_limit_krb5_enctypes: Calling gss_set_allowable_enctypes with 7 enctypes from the kernel
  Jun 22 11:25:13 SERVER rpc.svcgssd[7349]: WARNING: gss_accept_sec_context failed
  Jun 22 11:25:13 SERVER rpc.svcgssd[7349]: ERROR: GSS-API: error in handle_nullreq: gss_accept_sec_context(): GSS_S_FAILURE (Unspecified GSS failure.  Minor code may provide more information) - Wrong principal in request
  Jun 22 11:25:13 SERVER rpc.svcgssd[7349]: sending null reply
  Jun 22 11:25:13 SERVER rpc.svcgssd[7349]: writing message: \x \x6082029206092a864886f71201020201006e8202813082027da003020105a10302010ea20703050020000000a382017a6182017630820172a003020105a10b1b09504f4f4c532e534749a22b3029a003020101a12230201b036e66731b197073692e696e666f726d6174696b2e756e692d756c6d2e6465a382012f3082012ba003020112a103020101a282011d04820119a832e1fb8bf9170fa8a1f689868e2e4bacd8d4d1490c1d336b8bd90a61a11c8b669c5204fe73339f0fdab3d4770b78fdd745f5186a94ea55db90dbde79dc6c5b68c7c1ecba74f723c3fa3eb90ea412518c5da92497276b8a6e369ebb381ebdffa5d1d81e635c4e772892541f4c44475a5d87fc352c43c6e7dc6c0b37875383ec828a2d896948588fd84d442b6bf84b988f5e9bd251d2f71ea582709ecae4bd226705d263081f1036a85d0f13c240d740bf4377f7b6409dde7bd52acdcb396ea181cd54146bd93457801dd9edd0fcb1e27467e0f6ef615dae3f69a96060c463128875cbd414d6bf83af55c5132c814b9af5584852e21373fa774c05760e2c58eb719873c06c26acb2858dd6c4a81c89389cfede089df28f3e7ba481e93081e6a003020112a281de0481dbeedce4152a95ffbd19cccdb67033950e3b1c4aa2dca3b4ad147c9676286b726b02d8cc95b5fd842a2676551e10696ed4f3dfd2c91ec0f674a2017e97ab102aa13fefe02281de5116e8a4e62f93a4e0aff431155ae8b77229f71a6c03278e265eb7752b742b491adbbe5589263e19cf61f7b99cb615c97acc5b87a6008151c52ae4d6dd702a2d545cd23425df58ee37609930e0399fb4cf391a07fa08aa66da40a48491ce1fe6a9f58c30d4af039d191aa4f7b8e7c912ab76fcff685fc0ed6a82559f58b454d4cf61c28d3f962bfc43b265ce7d50ca769e1087bbfe 1403429173 851968 2529639056 \x \x 
  Jun 22 11:25:13 SERVER rpc.svcgssd[7349]: finished handling null request
  Jun 22 11:25:13 SERVER rpc.svcgssd[7349]: entering poll
  Jun 22 11:25:13 SERVER rpc.svcgssd[7349]: leaving poll
  Jun 22 11:25:13 SERVER rpc.svcgssd[7349]: handling null request
  Jun 22 11:25:13 SERVER rpc.svcgssd[7349]: svcgssd_limit_krb5_enctypes: Calling gss_set_allowable_enctypes with 7 enctypes from the kernel
  Jun 22 11:25:13 SERVER rpc.svcgssd[7349]: WARNING: gss_accept_sec_context failed
  Jun 22 11:25:13 SERVER rpc.svcgssd[7349]: ERROR: GSS-API: error in handle_nullreq: gss_accept_sec_context(): GSS_S_FAILURE (Unspecified GSS failure.  Minor code may provide more information) - Wrong principal in request
  Jun 22 11:25:13 SERVER rpc.svcgssd[7349]: sending null reply
  Jun 22 11:25:13 SERVER rpc.svcgssd[7349]: writing message: \x \x6082029206092a864886f71201020201006e8202813082027da003020105a10302010ea20703050020000000a382017a6182017630820172a003020105a10b1b09504f4f4c532e534749a22b3029a003020101a12230201b036e66731b197073692e696e666f726d6174696b2e756e692d756c6d2e6465a382012f3082012ba003020112a103020101a282011d04820119a832e1fb8bf9170fa8a1f689868e2e4bacd8d4d1490c1d336b8bd90a61a11c8b669c5204fe73339f0fdab3d4770b78fdd745f5186a94ea55db90dbde79dc6c5b68c7c1ecba74f723c3fa3eb90ea412518c5da92497276b8a6e369ebb381ebdffa5d1d81e635c4e772892541f4c44475a5d87fc352c43c6e7dc6c0b37875383ec828a2d896948588fd84d442b6bf84b988f5e9bd251d2f71ea582709ecae4bd226705d263081f1036a85d0f13c240d740bf4377f7b6409dde7bd52acdcb396ea181cd54146bd93457801dd9edd0fcb1e27467e0f6ef615dae3f69a96060c463128875cbd414d6bf83af55c5132c814b9af5584852e21373fa774c05760e2c58eb719873c06c26acb2858dd6c4a81c89389cfede089df28f3e7ba481e93081e6a003020112a281de0481dbfb0d5aa8041f95bbe86f7b8e6dcfb68a1c214d89bb8b5a7712b12e1346289ecf947595d783de2e5ceb32146a5a20c900097b495869d6d3b0533eed0407d71ecf7034a0e18805b5bfbdf3f5f543a70dbe86825d5bda491b4cbbe2ace745f4ae1d0e4d60a7fcc2089915236f59d9357f4ec549022c4aab322ed47b168507003fb5768b9e4c77c57b88b7f74b007dc0837ed560d9af6103aa105f53ecbc7b53c5e9170ad0add67b14a988b1388f93558cc43c4622eea107482e4f320ebbee3fe48acceb5e3e70a33f5ac7a5923c4251b1625e75179096c8b3de7fd934 1403429173 851968 2529639056 \x \x 
  Jun 22 11:25:13 SERVER rpc.svcgssd[7349]: finished handling null request
  Jun 22 11:25:13 SERVER rpc.svcgssd[7349]: entering poll

Exportfs:

/srv XXX.XXX.209.0/24(fsid=0,rw,no_subtree_check,root_squash,async,sec=sys:krb5:krb5i:krb5p)                                          
/srv tip*.example.com(fsid=0,rw,no_subtree_check,root_squash,async,sec=sys:krb5:krb5i:krb5p)                               
/srv pclab*.example.com(fsid=0,rw,no_subtree_check,root_squash,async,sec=sys:krb5:krb5i:krb5p)                             
                                                                    
/srv/home XXX.XXX.209.0/24(rw,no_subtree_check,root_squash,async,sec=sys:krb5:krb5i:krb5p)                                            
/srv/home tip*.example.com(rw,no_subtree_check,root_squash,async,sec=sys:krb5:krb5i:krb5p)                                 
/srv/home pclab*.example.com(rw,no_subtree_check,root_squash,async,sec=sys:krb5:krb5i:krb5p)                               
/srv/home XXX.XXX.208.0/24(rw,no_subtree_check,root_squash,async,sec=sys:krb5:krb5i:krb5p)                                            
/srv/home wslab*.example.com(rw,no_subtree_check,root_squash,async,sec=sys:krb5:krb5i:krb5p)                               
                                                                    
/srv/grpdrvs XXX.XXX.209.0/24(rw,no_subtree_check,root_squash,async,sec=sys:krb5:krb5i:krb5p)                                         
/srv/grpdrvs tip*.example.com(rw,no_subtree_check,root_squash,async,sec=sys:krb5:krb5i:krb5p)                              
/srv/grpdrvs pclab*.example.com(rw,no_subtree_check,root_squash,async,sec=sys:krb5:krb5i:krb5p)                            
/srv/grpdrvs XXX.XXX.208.0/24(rw,no_subtree_check,root_squash,async,sec=sys:krb5:krb5i:krb5p)

/etc/hosts:

127.0.0.1       localhost
XXX.XXX.209.52   SERVER.example.com      SERVER

# The following lines are desirable for IPv6 capable hosts
::1     localhost ip6-localhost ip6-loopback
ff02::1 ip6-allnodes
ff02::2 ip6-allrouters

Server and client:

/etc/idmapd:

[General]

Verbosity = 5
Pipefs-Directory = /run/rpc_pipefs
# set your own domain here, if id differs from FQDN minus hostname
Domain = example.com
Local-Realms = REALM
[Mapping]

Nobody-User = nobody
Nobody-Group = nogroup

NFS4 Client:

Mount request:

  mount -t nfs4 -o sec=krb5 SERVER:/ /mnt/temp/ -vvvv
  mount: fstab path: "/etc/fstab"
  mount: mtab path:  "/etc/mtab"
  mount: lock path:  "/etc/mtab~"
  mount: temp path:  "/etc/mtab.tmp"
  mount: UID:        0
  mount: eUID:       0
  mount: spec:  "SERVER:/"
  mount: node:  "/mnt/temp/"
  mount: types: "nfs4"
  mount: opts:  "sec=krb5"
  mount: external mount: argv[0] = "/sbin/mount.nfs4"
  mount: external mount: argv[1] = "SERVER:/"
  mount: external mount: argv[2] = "/mnt/temp/"
  mount: external mount: argv[3] = "-v"
  mount: external mount: argv[4] = "-o"
  mount: external mount: argv[5] = "rw,sec=krb5"
  mount.nfs4: timeout set for Sun Jun 22 11:24:33 2014
  mount.nfs4: trying text-based options 'sec=krb5,addr=XXX.XXX.XXX.52,clientaddr=XXX.XXX.XXX.42'
  mount.nfs4: mount(2): Permission denied
  mount.nfs4: access denied by server while mounting SERVER:/

Client logs:

  Jun 22 11:25:13 CLIENT rpc.gssd[708]: handling gssd upcall (/run/rpc_pipefs/nfs/clnt0)
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: handle_gssd_upcall: 'mech=krb5 uid=0 enctypes=18,17,16,23,3,1,2 '
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: handling krb5 upcall (/run/rpc_pipefs/nfs/clnt0)
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: process_krb5_upcall: service is '<null>'
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: Full hostname for 'SERVER.example.com' is 'SERVER.example.com'
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: Full hostname for 'CLIENT.example.com' is 'CLIENT.example.com'
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: No key table entry found for CLIENT$@REALM while getting keytab entry for 'CLIENT$@'
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: No key table entry found for root/CLIENT.example.com@REALM while getting keytab entry for 'root/CLIENT.example.com@'
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: Success getting keytab entry for 'nfs/CLIENT.example.com@'
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: INFO: Credentials in CC 'FILE:/tmp/krb5ccmachine_REALM' are good until 1403514481
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: INFO: Credentials in CC 'FILE:/tmp/krb5ccmachine_REALM' are good until 1403514481
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: using FILE:/tmp/krb5ccmachine_REALM as credentials cache for machine creds
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: using environment variable to select krb5 ccache FILE:/tmp/krb5ccmachine_REALM
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: creating context using fsuid 0 (save_uid 0)
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: creating tcp client for server SERVER.example.com
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: DEBUG: port already set to 2049
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: creating context with server [email protected]
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: WARNING: Failed to create krb5 context for user with uid 0 for server SERVER.example.com
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: WARNING: Failed to create machine krb5 context with credentials cache FILE:/tmp/krb5ccmachine_REALM for server SERVER.example.com
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: WARNING: Machine cache is prematurely expired or corrupted trying to recreate cache for server SERVER.example.com
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: Full hostname for 'SERVER.example.com' is 'SERVER.example.com'
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: Full hostname for 'CLIENT.example.com' is 'CLIENT.example.com'
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: No key table entry found for CLIENT$@REALM while getting keytab entry for 'CLIENT$@'
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: No key table entry found for root/CLIENT.example.com@REALM while getting keytab entry for 'root/CLIENT.example.com@'
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: Success getting keytab entry for 'nfs/CLIENT.example.com@'
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: INFO: Credentials in CC 'FILE:/tmp/krb5ccmachine_REALM' are good until 1403514481
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: INFO: Credentials in CC 'FILE:/tmp/krb5ccmachine_REALM' are good until 1403514481
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: using FILE:/tmp/krb5ccmachine_REALM as credentials cache for machine creds
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: using environment variable to select krb5 ccache FILE:/tmp/krb5ccmachine_REALM
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: creating context using fsuid 0 (save_uid 0)
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: creating tcp client for server SERVER.example.com
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: DEBUG: port already set to 2049
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: creating context with server [email protected]
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: WARNING: Failed to create krb5 context for user with uid 0 for server SERVER.example.com
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: WARNING: Failed to create machine krb5 context with credentials cache FILE:/tmp/krb5ccmachine_REALM for server SERVER.example.com
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: WARNING: Failed to create machine krb5 context with any credentials cache for server SERVER.example.com
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: doing error downcall
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: destroying client /run/rpc_pipefs/nfs/clnte
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: destroying client /run/rpc_pipefs/nfsd4_cb/clntd
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: destroying client /run/rpc_pipefs/nfsd4_cb/clnt7
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: destroying client /run/rpc_pipefs/nfsd4_cb/clnt6
  Jun 22 11:25:13 CLIENT rpc.gssd[708]: destroying client /run/rpc_pipefs/nfsd4_cb/clnt5

Client keytab:

% ktutil list                                                                                                             
FILE:/etc/krb5.keytab:

Vno  Type                     Principal                                     Aliases
  1  aes256-cts-hmac-sha1-96  host/CLIENT.example.com@REALM 
  1  des3-cbc-sha1            host/CLIENT.example.com@REALM 
  1  arcfour-hmac-md5         host/CLIENT.example.com@REALM 
  1  aes256-cts-hmac-sha1-96  nfs/CLIENT.example.com@REALM  
  1  des3-cbc-sha1            nfs/CLIENT.example.com@REALM  
  1  arcfour-hmac-md5         nfs/CLIENT.example.com@REALM

Client credential cache:

% klist -c /tmp/krb5ccmachine_REALM                                                            
Credentials cache: FILE:/tmp/krb5ccmachine_REALM
    Principal: nfs/CLIENT.example.com@REALM

  Issued                Expires               Principal
Jun 22 13:55:01 2014  Jun 23 13:55:01 2014  krbtgt/REALM@REALM
Jun 22 13:55:01 2014  Jun 23 13:55:01 2014  nfs/SERVER.example.com@REALM

Client /etc/hosts:

127.0.0.1 localhost
XXX.XXX.209.17 CLIENT.example.com CLIENT

DNS related:

Reverse DNS:

% host XXX.XXX.209.17
17.209.XXX.XXX.in-addr.arpa domain name pointer CLIENT.example.com.
% host XXX.XXX.209.52
52.209.XXX.XXX.in-addr.arpa domain name pointer SERVER.example.com.

getent hosts from SERVER:

root@SERVER:~# getent hosts CLIENT.example.com
XXX.XXX.209.17   CLIENT.example.com
root@SERVER:~# getent hosts SERVER.example.com
XXX.XXX.209.52   SERVER.example.com SERVER

getent hosts from CLIENT:

CLIENT 00:03:32 # getent hosts SERVER.example.com
XXX.XXX.209.52   SERVER.example.com
CLIENT 00:03:41 # getent hosts CLIENT.example.com
XXX.XXX.209.17   CLIENT.example.com CLIENT

I have been debugging this issue for weeks, but I haven't found a solution so far.

dawud about 10 years

Please add the /etc/exports configuration.
dawud about 10 years

Alternatively, if you're using an fsid=0, check that the sec= configuration is correct, too.
cebalrai about 10 years

I added the exports.
dawud about 10 years

Is name resolution working OK? (i.e., what's the output of dig SERVER.example.com and dig CLIENT.example.com?) Are you using local resolution or a DNS?
cebalrai about 10 years

I'm using DNS resolution. The /etc/hosts for the respective machines have 127.0.0.1 pointing to localhost and also have their IP pointing to their hostnames. 'hostname -f' gives the FQDN for both machines. Dig also shows the correct IPs for all involved machines.
Matthew Ife about 10 years

If you do the same for reverse DNS resolution these all match too right?
dawud about 10 years

According to this, and this, "All hosts in your realm must be resolvable (both forwards and reverse)" @MatthewIfe you beat me to it
cebalrai about 10 years

The Client:% host XXX.XXX.209.17 17.209.XXX.XXX.in-addr.arpa domain name pointer CLIENT.example.com. And the Server: % host XXX.XXX.209.52 52.209.XXX.XXX.in-addr.arpa domain name pointer SERVER.example.com. All resolve correctly. The error points to a DNS problem, but if it indeed is one, I haven't found it yet.