[Freeipa-users] Can mount NFS, but user only gets the permission question marks

[Kees Bakker]

On 02-03-17 13:34, Brendan Kearney wrote:
> On 03/02/2017 05:40 AM, Kees Bakker wrote:
>> On 24-02-17 14:38, Brendan Kearney wrote:
>>> On 02/24/2017 03:33 AM, Kees Bakker wrote:
>>>> On 23-02-17 15:39, Brendan Kearney wrote:
>>>>> On 02/23/2017 09:11 AM, Kees Bakker wrote:
>>>>>> On 23-02-17 13:51, Brendan Kearney wrote:
>>>>>>> On 02/23/2017 07:32 AM, Kees Bakker wrote:
>>>>>>>> On 22-02-17 17:33, Brendan Kearney wrote:
>>>>>>>>> On 02/22/2017 10:26 AM, Kees Bakker wrote:
>>>>>>>>>> On 22-02-17 14:05, Brendan Kearney wrote:
>>>>>>>>>>> On 02/22/2017 05:23 AM, Kees Bakker wrote:
>>>>>>>>>>>> On 21-02-17 19:49, Brendan Kearney wrote:
>>>>>>>>>>>>> On 02/21/2017 10:57 AM, Kees Bakker wrote:
>>>>>>>>>>>>>> Hey,
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> Maybe one of the NFS users on this list could give me a hint what
>>>>>>>>>>>>>> could be wrong. I'm not sure if it has any relation with FreeIPA/Kerberos.
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> I've set up an NFS server and I can mount the NFS directory on my client. So, I'm
>>>>>>>>>>>>>> guessing that setting up Kerberos principal was done correctly.
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> However, only root can actually access the mounted contents. Any other user
>>>>>>>>>>>>>> only sees question marks as shown below.
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> The mount command is simple.
>>>>>>>>>>>>>> $ sudo mount -v -t nfs srv1.example.com:/home /nfshome
>>>>>>>>>>>>>> mount.nfs: timeout set for Tue Feb 21 16:36:39 2017
>>>>>>>>>>>>>> mount.nfs: trying text-based options 'vers=4,addr=172.16.16.45,clientaddr=172.16.16.30'
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> On the server side /etc/exports looks like this.
>>>>>>>>>>>>>> /home        *(rw,sync,sec=krb5i,no_subtree_check)
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> $ sudo mount |grep nfs
>>>>>>>>>>>>>> srv1.example.com:/home on /nfshome type nfs4 (rw,relatime,vers=4.0,rsize=1048576,wsize=1048576,namlen=255,hard,proto=tcp,port=0,timeo=600,retrans=2,sec=krb5i,clientaddr=172.16.16.30,local_lock=none,addr=172.16.16.45)
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> $ sudo ls -ld /nfshome
>>>>>>>>>>>>>> drwxr-xr-x 1 root root 72 feb 21 04:22 /nfshome
>>>>>>>>>>>>>> $ sudo ls -l /nfshome
>>>>>>>>>>>>>> total 0
>>>>>>>>>>>>>> drwxr-xr-x 1 keesb  keesb  116 jan 27 12:56 keesb
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> $ ls -l /nfshome
>>>>>>>>>>>>>> ls: cannot access '/nfshome': Permission denied
>>>>>>>>>>>>>> $ ls -l / | grep nfshome
>>>>>>>>>>>>>> ls: cannot access '/nfshome': Permission denied
>>>>>>>>>>>>>> d?????????   ? ?    ?       ?            ? nfshome
>>>>>>>>>>>>>>
>> [...]
>>
>> Continuing story...
>>
>> I've tried various things in the meantime. I've set up two test environments with virtual
>> machines (virtualbox).
>> * with Fedora 25; this works.
>> * with Ubuntu 16.04; I'm getting the same problem (permission denied and question marks).
>>
>> I also looked at the verbose output of rpc.gssd, it gives
>>
>> ERROR: GSS-API: error in gss_acquire_cred(): GSS_S_FAILURE (Unspecified GSS failure.  Minor code may provide more information) - Can't find client principal keesb at REALM in cache collection
> does the actual error message say @REALM, or did you substitute that to obscure sensitive info?  if it does actually say @REALM, then you are missing a config directive somewhere, that specifies the kerberos realm.

Be assured that I'm using the real thing.

>> getting credentials for client with uid 60001 for server srv1.example.com
>> getting credentials for client with uid 60001 for server srv1.example.com
>> WARNING: Failed to create krb5 context for user with uid 60001 for server srv1.example.com

So rpc.gssd is trying to create a krb5 context. It succeeds for uid=0 but not for another
user.

Log when root is listing the NFS directory
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: handling gssd upcall (/run/rpc_pipefs/nfs/clnt14)
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: handle_gssd_upcall: 'mech=krb5 uid=0 service=* enctypes=18,17,16,23,3,1,2 '
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: handling krb5 upcall (/run/rpc_pipefs/nfs/clnt14)
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: process_krb5_upcall: service is '*'
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: Full hostname for 'srv1.example.com' is 'srv1.example.com'
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: Full hostname for 'clnt1.example.com' is 'clnt1.example.com'
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: No key table entry found for CLNT1.REALM$@REALM while getting keytab entry for 'CLNT1.REALM$@REALM'
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: No key table entry found for root/clnt1.example.com at REALM while getting keytab entry for 'root/clnt1.example.com at REALM'
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: No key table entry found for nfs/clnt1.example.com at REALM while getting keytab entry for 'nfs/clnt1.example.com at REALM'
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: Success getting keytab entry for 'host/clnt1.example.com at REALM'
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: INFO: Credentials in CC 'FILE:/tmp/krb5ccmachine_REALM' are good until 1488535153
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: INFO: Credentials in CC 'FILE:/tmp/krb5ccmachine_REALM' are good until 1488535153
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: using FILE:/tmp/krb5ccmachine_REALM as credentials cache for machine creds
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: using environment variable to select krb5 ccache FILE:/tmp/krb5ccmachine_REALM
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: creating context using fsuid 0 (save_uid 0)
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: creating tcp client for server srv1.example.com
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: DEBUG: port already set to 2049
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: creating context with server nfs at srv1.example.com
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: DEBUG: serialize_krb5_ctx: lucid version!
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: prepare_krb5_rfc4121_buffer: protocol 1
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: prepare_krb5_rfc4121_buffer: serializing key with enctype 18 and size 32
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: doing downcall lifetime_rec 74121
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: handling gssd upcall (/run/rpc_pipefs/nfs/clnt14)
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: handle_gssd_upcall: 'mech=krb5 uid=0 enctypes=18,17,16,23,3,1,2 '
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: handling krb5 upcall (/run/rpc_pipefs/nfs/clnt14)
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: process_krb5_upcall: service is '<null>'
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: Full hostname for 'srv1.example.com' is 'srv1.example.com'
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: Full hostname for 'clnt1.example.com' is 'clnt1.example.com'
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: No key table entry found for CLNT1.REALM$@REALM while getting keytab entry for 'CLNT1.REALM$@REALM'
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: No key table entry found for root/clnt1.example.com at REALM while getting keytab entry for 'root/clnt1.example.com at REALM'
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: No key table entry found for nfs/clnt1.example.com at REALM while getting keytab entry for 'nfs/clnt1.example.com at REALM'
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: Success getting keytab entry for 'host/clnt1.example.com at REALM'
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: INFO: Credentials in CC 'FILE:/tmp/krb5ccmachine_REALM' are good until 1488535153
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: INFO: Credentials in CC 'FILE:/tmp/krb5ccmachine_REALM' are good until 1488535153
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: using FILE:/tmp/krb5ccmachine_REALM as credentials cache for machine creds
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: using environment variable to select krb5 ccache FILE:/tmp/krb5ccmachine_REALM
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: creating context using fsuid 0 (save_uid 0)
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: creating tcp client for server srv1.example.com
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: DEBUG: port already set to 2049
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: creating context with server nfs at srv1.example.com
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: DEBUG: serialize_krb5_ctx: lucid version!
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: prepare_krb5_rfc4121_buffer: protocol 1
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: prepare_krb5_rfc4121_buffer: serializing key with enctype 18 and size 32
Mar  2 14:23:52 clnt1 rpc.gssd[3612]: doing downcall lifetime_rec 74121
Mar  2 14:23:53 clnt1 rpc.gssd[3612]: destroying client /run/rpc_pipefs/nfs/clnt16
Mar  2 14:23:53 clnt1 rpc.gssd[3612]: destroying client /run/rpc_pipefs/nfs/clnt15

Log when the user is listing the directory
Mar  2 14:24:00 clnt1 rpc.gssd[3612]: handling gssd upcall (/run/rpc_pipefs/nfs/clnt14)
Mar  2 14:24:00 clnt1 rpc.gssd[3612]: handle_gssd_upcall: 'mech=krb5 uid=60001 enctypes=18,17,16,23,3,1,2 '
Mar  2 14:24:00 clnt1 rpc.gssd[3612]: handling krb5 upcall (/run/rpc_pipefs/nfs/clnt14)
Mar  2 14:24:00 clnt1 rpc.gssd[3612]: process_krb5_upcall: service is '<null>'
Mar  2 14:24:00 clnt1 rpc.gssd[3612]: ERROR: GSS-API: error in gss_acquire_cred(): GSS_S_FAILURE (Unspecified GSS failure.  Minor code may provide more information) - Can't find client principal keesb at REALM in cache collection
Mar  2 14:24:00 clnt1 rpc.gssd[3612]: getting credentials for client with uid 60001 for server srv1.example.com
Mar  2 14:24:00 clnt1 rpc.gssd[3612]: CC '/tmp/krb5ccmachine_REALM' being considered, with preferred realm 'REALM'
Mar  2 14:24:00 clnt1 rpc.gssd[3612]: CC '/tmp/krb5ccmachine_REALM' owned by 0, not 60001
Mar  2 14:24:00 clnt1 rpc.gssd[3612]: getting credentials for client with uid 60001 for server srv1.example.com
Mar  2 14:24:00 clnt1 rpc.gssd[3612]: WARNING: Failed to create krb5 context for user with uid 60001 for server srv1.example.com
Mar  2 14:24:00 clnt1 rpc.gssd[3612]: doing error downcall

As an experiment I have changed ownership of /tmp/krb5ccmachine_REALM to uid 60001.
And now the user can list the NFS directory. The gssd log
Mar  2 14:36:40 clnt1 rpc.gssd[3612]: handling gssd upcall (/run/rpc_pipefs/nfs/clnt14)
Mar  2 14:36:40 clnt1 rpc.gssd[3612]: handle_gssd_upcall: 'mech=krb5 uid=60001 enctypes=18,17,16,23,3,1,2 '
Mar  2 14:36:40 clnt1 rpc.gssd[3612]: handling krb5 upcall (/run/rpc_pipefs/nfs/clnt14)
Mar  2 14:36:40 clnt1 rpc.gssd[3612]: process_krb5_upcall: service is '<null>'
Mar  2 14:36:40 clnt1 rpc.gssd[3612]: ERROR: GSS-API: error in gss_acquire_cred(): GSS_S_FAILURE (Unspecified GSS failure.  Minor code may provide more information) - Can't find client principal keesb at REALM in cache collection
Mar  2 14:36:40 clnt1 rpc.gssd[3612]: getting credentials for client with uid 60001 for server srv1.example.com
Mar  2 14:36:40 clnt1 rpc.gssd[3612]: CC '/tmp/krb5ccmachine_REALM' being considered, with preferred realm 'REALM'
Mar  2 14:36:40 clnt1 rpc.gssd[3612]: CC 'FILE:/tmp/krb5ccmachine_REALM'(host/clnt1.example.com at REALM) passed all checks and has mtime of 1488448753
Mar  2 14:36:40 clnt1 rpc.gssd[3612]: using FILE:/tmp/krb5ccmachine_REALM as credentials cache for client with uid 60001 for server srv1.example.com
Mar  2 14:36:40 clnt1 rpc.gssd[3612]: using environment variable to select krb5 ccache FILE:/tmp/krb5ccmachine_REALM
Mar  2 14:36:40 clnt1 rpc.gssd[3612]: creating context using fsuid 60001 (save_uid 0)
Mar  2 14:36:40 clnt1 rpc.gssd[3612]: creating tcp client for server srv1.example.com
Mar  2 14:36:40 clnt1 rpc.gssd[3612]: DEBUG: port already set to 2049
Mar  2 14:36:40 clnt1 rpc.gssd[3612]: creating context with server nfs at srv1.example.com
Mar  2 14:36:40 clnt1 rpc.gssd[3612]: DEBUG: serialize_krb5_ctx: lucid version!
Mar  2 14:36:40 clnt1 rpc.gssd[3612]: prepare_krb5_rfc4121_buffer: protocol 1
Mar  2 14:36:40 clnt1 rpc.gssd[3612]: prepare_krb5_rfc4121_buffer: serializing key with enctype 18 and size 32
Mar  2 14:36:40 clnt1 rpc.gssd[3612]: doing downcall lifetime_rec 73353

I'm guessing the solution must be in that area. The credentials cache must be somewhere where
the user can have access to it. How would I do that?

>>
>> But the user really did get a TGT.
>>
>> $ klist
>> Ticket cache: KEYRING:persistent:60001:60001
>> Default principal: keesb at EXAMPLE.COM
>>
>> Valid starting     Expires            Service principal
>> 02-03-17 10:25:25  03-03-17 10:25:22  krbtgt/EXAMPLE.COM at EXAMPLE.COM
>>
>> So, still no solution for Ubuntu + freeipa + nfs.
>>
>> BTW. I've enabled verbosity in /etc/idmapd.conf. The logging tells me it is OK. However,
>> there is only any output when root (uid 0) does a NFS directory lookup. When a regular
>> user tries to stat the NFS directory it does not even get to the point where id mapping is
>> done.
>
>