Oracle Linux won't mount CentOS NFS share, but Arch will

Question

I'm trying to get kerberized NFSv4 running on our network. Server is CentOS 7. I'm able to mount the share on my Arch Linux workstation, but not our Oracle Linux 7 database servers.

I'm trying to mount from testdb with the command:

mount -v -t nfs4 -o rw,proto=tcp,vers=4.1,port=2049,sec=krb5 gs-storage.ad.goldblattsystems.com:/dba_work /dba_work

Which returns (stdout and /var/log/messages):

mount.nfs4: timeout set for Mon Sep 17 12:11:40 2018
mount.nfs4: trying text-based options 'proto=tcp,vers=4.1,port=2049,sec=krb5,addr=192.168.5.30,clientaddr=192.168.5.32'
Sep 17 12:09:40 testdb kernel: NFS: nfs mount opts='proto=tcp,vers=4.1,port=2049,sec=krb5,addr=192.168.5.30,clientaddr=192.168.5.32'
Sep 17 12:09:40 testdb kernel: NFS:   parsing nfs mount option 'proto=tcp'
Sep 17 12:09:40 testdb kernel: NFS:   parsing nfs mount option 'vers=4.1'
Sep 17 12:09:40 testdb kernel: NFS:   parsing nfs mount option 'port=2049'
Sep 17 12:09:40 testdb kernel: NFS:   parsing nfs mount option 'sec=krb5'
Sep 17 12:09:40 testdb kernel: NFS: parsing sec=krb5 option
Sep 17 12:09:40 testdb kernel: NFS:   parsing nfs mount option 'addr=192.168.5.30'
Sep 17 12:09:40 testdb kernel: NFS:   parsing nfs mount option 'clientaddr=192.168.5.32'
Sep 17 12:09:40 testdb kernel: NFS: MNTPATH: '/dba_work'
Sep 17 12:09:40 testdb kernel: --> nfs4_try_mount()
Sep 17 12:09:40 testdb kernel: --> nfs4_create_server()
Sep 17 12:09:40 testdb kernel: --> nfs4_init_server()
Sep 17 12:09:40 testdb kernel: --> nfs_get_client(gs-storage.ad.goldblattsystems.com,v4)
Sep 17 12:09:40 testdb kernel: NFS: get client cookie (0xffff88061f3c3800/0xffff8801166af528)
Sep 17 12:09:40 testdb kernel: nfs_callback_create_svc: service created
Sep 17 12:09:40 testdb kernel: NFS: create per-net callback data; net=ffffffff81c60000
Sep 17 12:09:40 testdb kernel: NFS: svc_create_xprt(tcp-bc) returned 0
Sep 17 12:09:40 testdb kernel: --> nfs41_callback_up return 0
Sep 17 12:09:40 testdb kernel: nfs_callback_up: service started
Sep 17 12:09:40 testdb kernel: NFS: nfs4_discover_server_trunking: testing 'gs-storage.ad.goldblattsystems.com'
Sep 17 12:09:40 testdb kernel: NFS call  exchange_id auth=RPCSEC_GSS, 'Linux NFSv4.1 testdb'
Sep 17 12:09:40 testdb kernel: NFS reply exchange_id: -13
Sep 17 12:09:40 testdb kernel: NFS call  exchange_id auth=RPCSEC_GSS, 'Linux NFSv4.1 testdb'
Sep 17 12:09:40 testdb kernel: NFS reply exchange_id: -13
Sep 17 12:09:40 testdb kernel: NFS call  exchange_id auth=RPCSEC_GSS, 'Linux NFSv4.1 testdb'
Sep 17 12:09:41 testdb kernel: NFS reply exchange_id: -13
Sep 17 12:09:41 testdb kernel: NFS call  exchange_id auth=RPCSEC_GSS, 'Linux NFSv4.1 testdb'
Sep 17 12:09:41 testdb kernel: NFS reply exchange_id: -13
Sep 17 12:09:41 testdb kernel: NFS call  exchange_id auth=UNIX, 'Linux NFSv4.1 testdb'
Sep 17 12:09:41 testdb kernel: NFS reply exchange_id: Server Implementation ID: domain: , name: , date: 0,0
Sep 17 12:09:41 testdb kernel: NFS reply exchange_id: 0
Sep 17 12:09:41 testdb kernel: NFS: <-- nfs41_walk_client_list using nfs_client = ffff88061f3c3800 ({2})
Sep 17 12:09:41 testdb kernel: NFS: <-- nfs41_walk_client_list status = 0
Sep 17 12:09:41 testdb kernel: NFS call  exchange_id auth=UNIX, 'Linux NFSv4.1 testdb'
Sep 17 12:09:41 testdb kernel: NFS reply exchange_id: Server Implementation ID: domain: , name: , date: 0,0
Sep 17 12:09:41 testdb kernel: NFS reply exchange_id: 0
Sep 17 12:09:41 testdb kernel: --> nfs4_proc_create_session clp=ffff88061f3c3800 session=ffff880622919400
Sep 17 12:09:41 testdb kernel: nfs4_init_channel_attrs: Fore Channel : max_rqst_sz=1049620 max_resp_sz=1049480 max_ops=8 max_reqs=64
Sep 17 12:09:41 testdb kernel: nfs4_init_channel_attrs: Back Channel : max_rqst_sz=4096 max_resp_sz=4096 max_resp_sz_cached=0 max_ops=2 max_reqs=1
Sep 17 12:09:41 testdb kernel: --> nfs4_setup_session_slot_tables
Sep 17 12:09:41 testdb kernel: --> nfs4_realloc_slot_table: max_reqs=10, tbl->max_slots 0
Sep 17 12:09:41 testdb kernel: nfs4_realloc_slot_table: tbl=ffff880622919440 slots=ffff88013a4a5380 max_slots=10
Sep 17 12:09:41 testdb kernel: <-- nfs4_realloc_slot_table: return 0
Sep 17 12:09:41 testdb kernel: --> nfs4_realloc_slot_table: max_reqs=1, tbl->max_slots 0
Sep 17 12:09:41 testdb kernel: nfs4_realloc_slot_table: tbl=ffff880622919608 slots=ffff88013a4a5040 max_slots=1
Sep 17 12:09:41 testdb kernel: <-- nfs4_realloc_slot_table: return 0
Sep 17 12:09:41 testdb kernel: slot table setup returned 0
Sep 17 12:09:41 testdb kernel: nfs4_proc_create_session client>seqid 2 sessionid 1534807995:93024321:52:0
Sep 17 12:09:41 testdb kernel: <-- nfs4_proc_create_session
Sep 17 12:09:41 testdb kernel: nfs4_schedule_state_renewal: requeueing work. Lease period = 5
Sep 17 12:09:41 testdb kernel: --> nfs41_proc_reclaim_complete
Sep 17 12:09:41 testdb kernel: --> nfs41_setup_sequence
Sep 17 12:09:41 testdb kernel: --> nfs4_alloc_slot used_slots=0000 highest_used=4294967295 max_slots=10
Sep 17 12:09:41 testdb kernel: <-- nfs4_alloc_slot used_slots=0001 highest_used=0 slotid=0
Sep 17 12:09:41 testdb kernel: <-- nfs41_setup_sequence slotid=0 seqid=1
Sep 17 12:09:41 testdb kernel: NFS: nfs4_discover_server_trunking: status = 0
Sep 17 12:09:41 testdb kernel: encode_sequence: sessionid=1534807995:93024321:52:0 seqid=1 slotid=0 max_slotid=0 cache_this=0
Sep 17 12:09:41 testdb kernel: --> nfs_put_client({3})
Sep 17 12:09:41 testdb kernel: <-- nfs4_init_server() = 0
Sep 17 12:09:41 testdb kernel: --> nfs4_get_rootfh()
Sep 17 12:09:41 testdb kernel: --> nfs41_call_sync_prepare data->seq_server ffff88061eabf000
Sep 17 12:09:41 testdb kernel: --> nfs41_setup_sequence
Sep 17 12:09:41 testdb kernel: nfs41_setup_sequence session is draining
Sep 17 12:09:41 testdb kernel: --> nfs4_reclaim_complete_done
Sep 17 12:09:41 testdb kernel: --> nfs4_alloc_slot used_slots=0001 highest_used=0 max_slots=10
Sep 17 12:09:41 testdb kernel: <-- nfs4_alloc_slot used_slots=0003 highest_used=1 slotid=1
Sep 17 12:09:41 testdb kernel: nfs4_free_slot: slotid 1 highest_used_slotid 0
Sep 17 12:09:41 testdb kernel: nfs41_sequence_done: Error 0 free the slot
Sep 17 12:09:41 testdb kernel: nfs4_free_slot: slotid 0 highest_used_slotid 4294967295
Sep 17 12:09:41 testdb kernel: <-- nfs4_reclaim_complete_done
Sep 17 12:09:41 testdb kernel: --> nfs4_alloc_slot used_slots=0000 highest_used=4294967295 max_slots=1
Sep 17 12:09:41 testdb kernel: <-- nfs4_alloc_slot used_slots=0001 highest_used=0 slotid=0
Sep 17 12:09:41 testdb kernel: nfs4_free_slot: slotid 0 highest_used_slotid 4294967295
Sep 17 12:09:41 testdb kernel: --> nfs4_alloc_slot used_slots=0000 highest_used=4294967295 max_slots=10
Sep 17 12:09:41 testdb kernel: <-- nfs4_alloc_slot used_slots=0001 highest_used=0 slotid=0
Sep 17 12:09:41 testdb kernel: --> nfs4_alloc_slot used_slots=0001 highest_used=0 max_slots=10
Sep 17 12:09:41 testdb kernel: <-- nfs4_alloc_slot used_slots=0003 highest_used=1 slotid=1
Sep 17 12:09:41 testdb kernel: nfs4_free_slot: slotid 1 highest_used_slotid 0
Sep 17 12:09:41 testdb kernel: --> nfs_put_client({2})
Sep 17 12:09:41 testdb kernel: --> nfs41_call_sync_prepare data->seq_server ffff88061eabf000
Sep 17 12:09:41 testdb kernel: --> nfs41_setup_sequence
Sep 17 12:09:41 testdb kernel: nfs41_sequence_done: Error 1 free the slot
Sep 17 12:09:41 testdb kernel: nfs4_free_slot: slotid 0 highest_used_slotid 4294967295
Sep 17 12:09:41 testdb kernel: nfs4_get_rootfh: getroot error = 13
Sep 17 12:09:41 testdb kernel: <-- nfs4_get_rootfh() = -13
Sep 17 12:09:41 testdb kernel: --> nfs_free_server()
Sep 17 12:09:41 testdb kernel: --> nfs_put_client({1})
Sep 17 12:09:41 testdb kernel: --> nfs4_proc_destroy_session
Sep 17 12:09:41 testdb kernel: <-- nfs4_proc_destroy_session
Sep 17 12:09:41 testdb kernel: nfs4_destroy_session Destroy backchannel for xprt ffff88061eabb000
Sep 17 12:09:41 testdb kernel: NFS: destroy per-net callback data; net=ffffffff81c60000
mount.nfs4: mount(2): Permission denied
mount.nfs4: access denied by server while mounting gs-storage.ad.goldblattsystems.com:/dba_work
Sep 17 12:09:41 testdb kernel: nfs_callback_down: service stopped
Sep 17 12:09:41 testdb kernel: nfs_callback_down: service destroyed
Sep 17 12:09:41 testdb kernel: --> nfs_free_client(4)
Sep 17 12:09:41 testdb kernel: NFS: releasing client cookie (0xffff88061f3c3800/0xffff8801166af528)
Sep 17 12:09:41 testdb kernel: <-- nfs_free_client()
Sep 17 12:09:41 testdb kernel: <-- nfs_free_server()
Sep 17 12:09:41 testdb kernel: <-- nfs4_create_server() = error -13
Sep 17 12:09:41 testdb kernel: <-- nfs4_try_mount() = -13 [error]

I've used net ads keytab add nfs to create the necessary keytab on both sides. What am I doing wrong? More debugging info follows:

/data          192.168.0.0/16(rw,no_subtree_check,sync,no_root_squash,insecure,sec=krb5:krb5i:krb5p,fsid=0)
/data/dba_work 192.168.0.0/16(rw,no_subtree_check,sync,no_root_squash,insecure,sec=krb5:krb5i:krb5p,fsid=1)

Environment overview:

      Server          Client
      ============================
Name: gs-storage      testdb
IP:   192.168.5.30    192.168.5.32
OS:   CentOS 7        Oracle Linux 7

Here is the /var/log/messages output from the server when mounting, activated using rpcdebug -m nfsd all:

Sep 17 12:08:32 gs-storage kernel: nfsd_dispatch: vers 4 proc 0
Sep 17 12:08:32 gs-storage kernel: nfsd_dispatch: vers 4 proc 1
Sep 17 12:08:32 gs-storage kernel: nfsv4 compound op #1/1: 42 (OP_EXCHANGE_ID)
Sep 17 12:08:32 gs-storage kernel: nfsd4_exchange_id rqstp=ffff9484f90ec000 exid=ffff94886989e0a0 clname.len=20 clname.data=ffff94886636c060 ip_addr=192.168.5.32 flags 103, spa_how 0
Sep 17 12:08:32 gs-storage kernel: renewing client (clientid 5b7b4fbb/058b7040)
Sep 17 12:08:32 gs-storage kernel: nfsd4_exchange_id seqid 0 flags 20001
Sep 17 12:08:32 gs-storage kernel: nfsv4 compound op ffff94886989e080 opcnt 1 #1: 42: status 0
Sep 17 12:08:32 gs-storage kernel: nfsv4 compound returned 0
Sep 17 12:08:32 gs-storage kernel: nfsd_dispatch: vers 4 proc 1
Sep 17 12:08:32 gs-storage kernel: nfsv4 compound op #1/1: 42 (OP_EXCHANGE_ID)
Sep 17 12:08:32 gs-storage kernel: nfsd4_exchange_id rqstp=ffff9484f90ec000 exid=ffff94886989e0a0 clname.len=20 clname.data=ffff94886636c060 ip_addr=192.168.5.32 flags 103, spa_how 0
Sep 17 12:08:32 gs-storage kernel: renewing client (clientid 5b7b4fbb/058b7041)
Sep 17 12:08:32 gs-storage kernel: nfsd4_exchange_id seqid 0 flags 20001
Sep 17 12:08:32 gs-storage kernel: nfsv4 compound op ffff94886989e080 opcnt 1 #1: 42: status 0
Sep 17 12:08:32 gs-storage kernel: nfsv4 compound returned 0
Sep 17 12:08:32 gs-storage kernel: nfsd_dispatch: vers 4 proc 1
Sep 17 12:08:32 gs-storage kernel: nfsv4 compound op #1/1: 43 (OP_CREATE_SESSION)
Sep 17 12:08:32 gs-storage kernel: renewing client (clientid 5b7b4fbb/058b7041)
Sep 17 12:08:32 gs-storage kernel: check_slot_seqid enter. seqid 1 slot_seqid 0
Sep 17 12:08:32 gs-storage kernel: NFSD: move_to_confirm nfs4_client ffff948844b8f800
Sep 17 12:08:32 gs-storage kernel: renewing client (clientid 5b7b4fbb/058b7041)
Sep 17 12:08:32 gs-storage kernel: renewing client (clientid 5b7b4fbb/058b7041)
Sep 17 12:08:32 gs-storage kernel: nfsv4 compound op ffff94886989e080 opcnt 1 #1: 43: status 0
Sep 17 12:08:32 gs-storage kernel: nfsv4 compound returned 0
Sep 17 12:08:32 gs-storage kernel: nfsd_dispatch: vers 4 proc 1
Sep 17 12:08:32 gs-storage kernel: nfsv4 compound op #1/2: 53 (OP_SEQUENCE)
Sep 17 12:08:32 gs-storage kernel: __find_in_sessionid_hashtbl: 1534807995:93024321:52:0
Sep 17 12:08:32 gs-storage kernel: nfsd4_sequence: slotid 0
Sep 17 12:08:32 gs-storage kernel: check_slot_seqid enter. seqid 1 slot_seqid 0
Sep 17 12:08:32 gs-storage kernel: nfsv4 compound op ffff94886989e080 opcnt 2 #1: 53: status 0
Sep 17 12:08:32 gs-storage kernel: nfsv4 compound op #2/2: 58 (OP_RECLAIM_COMPLETE)
Sep 17 12:08:32 gs-storage kernel: nfsd4_umh_cltrack_upcall: cmd: create
Sep 17 12:08:32 gs-storage kernel: nfsd4_umh_cltrack_upcall: arg: 4c696e7578204e465376342e3120746573746462
Sep 17 12:08:32 gs-storage kernel: nfsd4_umh_cltrack_upcall: env0: NFSDCLTRACK_CLIENT_HAS_SESSION=Y
Sep 17 12:08:32 gs-storage kernel: nfsd4_umh_cltrack_upcall: env1: NFSDCLTRACK_GRACE_START=1534807995
Sep 17 12:08:32 gs-storage kernel: nfsd4_umh_cltrack_upcall: /sbin/nfsdcltrack return value: 0
Sep 17 12:08:32 gs-storage kernel: nfsv4 compound op ffff94886989e080 opcnt 2 #2: 58: status 0
Sep 17 12:08:32 gs-storage kernel: nfsv4 compound returned 0
Sep 17 12:08:32 gs-storage kernel: --> nfsd4_store_cache_entry slot ffff9488443ca000
Sep 17 12:08:32 gs-storage kernel: renewing client (clientid 5b7b4fbb/058b7041)
Sep 17 12:08:32 gs-storage kernel: nfsd_dispatch: vers 4 proc 1
Sep 17 12:08:32 gs-storage kernel: nfsv4 compound op #1/1: 44 (OP_DESTROY_SESSION)
Sep 17 12:08:32 gs-storage kernel: nfsd4_destroy_session: 1534807995:93024321:52:0
Sep 17 12:08:32 gs-storage kernel: __find_in_sessionid_hashtbl: 1534807995:93024321:52:0
Sep 17 12:08:32 gs-storage kernel: NFSD: warning: no callback path to client Linux NFSv4.1 testdb: error -22
Sep 17 12:08:32 gs-storage kernel: renewing client (clientid 5b7b4fbb/058b7041)
Sep 17 12:08:32 gs-storage kernel: nfsv4 compound op ffff94886989e080 opcnt 1 #1: 44: status 0
Sep 17 12:08:32 gs-storage kernel: nfsv4 compound returned 0
Sep 17 12:08:33 gs-storage kernel: nfsd_dispatch: vers 4 proc 1
Sep 17 12:08:33 gs-storage kernel: nfsv4 compound op #1/1: 57 (OP_DESTROY_CLIENTID)
Sep 17 12:08:33 gs-storage kernel: renewing client (clientid 5b7b4fbb/058b7041)
Sep 17 12:08:33 gs-storage kernel: nfsd4_umh_cltrack_upcall: cmd: remove
Sep 17 12:08:33 gs-storage kernel: nfsd4_umh_cltrack_upcall: arg: 4c696e7578204e465376342e3120746573746462
Sep 17 12:08:33 gs-storage kernel: nfsd4_umh_cltrack_upcall: env0: (null)
Sep 17 12:08:33 gs-storage kernel: nfsd4_umh_cltrack_upcall: env1: (null)
Sep 17 12:08:33 gs-storage kernel: nfsd4_umh_cltrack_upcall: /sbin/nfsdcltrack return value: 0
Sep 17 12:08:33 gs-storage kernel: nfsv4 compound op ffff94886989e080 opcnt 1 #1: 57: status 0
Sep 17 12:08:33 gs-storage kernel: nfsv4 compound returned 0

Edit: The question marked as a duplicate of this does not fit this circumstance. krb5 is an enabled auth/transport mechanism. In addition, the error in the other question is completely different from in this one.

@MichaelHampton, your answer to that other question is not correct for this circumstance. I have krb5 and krb5i enabled in addition to krb5p. I was able to successfully mount using krb5 on one box. — Dessa Simpson, Sep 10 '18 at 16:54
@titus Problem signature is identical whether enforcing or permissive — Dessa Simpson, Sep 17 '18 at 18:10
Have you tried disabled, just for the sake of troubleshooting? — titus, Sep 17 '18 at 18:12
Kerberos could be picky about the names. Have you tried to use FQDN in mount command? I also think that nfs client log may have relevant information. — Tomek, Sep 17 '18 at 18:58
@Tomek Just tried, FQDNs doesn't change anything, and even after `rpcdebug -m nfsd all` on the client, `/var/log/messages` doesn't change after a mount command. — Dessa Simpson, Sep 17 '18 at 19:03
@Tomek I just realized the flaw with my rpcdebug. Trying with client debugging enabled — Dessa Simpson, Sep 17 '18 at 19:04
@Tomek Edited question. Added client logs, synchronized all logs and output (now all from same attempt), and fixed innacuracies regarding which hosts had which OS — Dessa Simpson, Sep 17 '18 at 19:14

score 1 · Answer 1 · answered Sep 17 '18 at 21:40

This:

Sep 17 12:09:40 testdb kernel: NFS call  exchange_id auth=RPCSEC_GSS, 'Linux NFSv4.1 testdb'
Sep 17 12:09:40 testdb kernel: NFS reply exchange_id: -13

makes me thinking that rpc.gssd is possibly not running and there is a fallback to sys security right after it:

Sep 17 12:09:41 testdb kernel: NFS call  exchange_id auth=UNIX, 'Linux NFSv4.1 testdb'
Sep 17 12:09:41 testdb kernel: NFS reply exchange_id: Server Implementation ID: domain: , name: , date: 0,0
Sep 17 12:09:41 testdb kernel: NFS reply exchange_id: 0

Is nfs-secure service running?

Additionally please check if id_resolver is properly setup. Check /etc/request-key.conf and /etc/request-key.d/*.conf for line like that:

create    id_resolver    *         *    /usr/sbin/nfsidmap %k %d

nfs-secure is running. `/etc/request-key.d/id_resolver.conf` contains `create id_resolver * * /usr/sbin/nfsidmap %k %d`. — Dessa Simpson, Sep 17 '18 at 22:44

Oracle Linux won't mount CentOS NFS share, but Arch will

1 Answers1