Hi,
I'm trying to get NFS4J working with Kerberos on Ubuntu 20.04. OS native NFS server with Kerberos works fine as well as NFS4J without authentication. But with both NFS4J and Kerberos, I invariably have an access denied on the client side.
sudo mount -t nfs -o sec=krb5 -o vers=4.1 -vvvv localhost:/ /mnt/export
mount.nfs: timeout set for Wed May 19 11:17:42 2021
mount.nfs: trying text-based options 'sec=krb5,vers=4.1,addr=127.0.0.1,clientaddr=127.0.0.1'
mount.nfs: mount(2): Permission denied
mount.nfs: access denied by server while mounting localhost:/
This is my export file content:
/ *(sec=krb5,rw,no_root_squash)
I also followed instructions from this link:
https://dcache.org/old/manuals/Book-2.3/config/cf-nfs4-gss-fhs-comments.shtml
And this is the debug output from the server:
2021-05-19 11:15:11.202 [] [main] INFO w.g.n.Daemon - Share has been attached: ShareConfig{path=., alias='/', permissions=null, globPermissions=null}
2021-05-19 11:15:11.276 [] [main] INFO o.d.o.p.OncRpcEmbeddedPortmap - Local portmap service v4 detected
2021-05-19 11:15:11.279 [] [main] INFO o.d.o.r.OncRpcSvc - Registering new program [100005:3] : org.dcache.nfs.v3.MountServer@2101b44a
2021-05-19 11:15:11.279 [] [main] INFO o.d.o.r.OncRpcSvc - Registering new program [100003:3] : org.dcache.nfs.v3.NfsServerV3@2cc3ad05
2021-05-19 11:15:11.279 [] [main] INFO o.d.o.r.OncRpcSvc - Registering new program [100003:4] : org.dcache.nfs.v4.NFSServerV41@710b18a6
2021-05-19 11:15:11.282 [] [main] DEBUG o.d.o.p.RpcbindV4Client - portmap ping
2021-05-19 11:15:11.283 [] [main] DEBUG o.d.o.p.RpcbindV4Client - portmap unset port: prog: 100003 vers: 3, owner: eric
2021-05-19 11:15:11.284 [] [main] DEBUG o.d.o.p.RpcbindV4Client - portmap unset port: prog: 100003 vers: 4, owner: eric
2021-05-19 11:15:11.285 [] [main] DEBUG o.d.o.p.RpcbindV4Client - portmap unset port: prog: 100005 vers: 3, owner: eric
2021-05-19 11:15:11.291 [] [main] DEBUG o.d.o.p.RpcbindV4Client - portmap ping
2021-05-19 11:15:11.293 [] [main] DEBUG o.d.o.p.RpcbindV4Client - portmap set port: prog: 100003 vers: 3, netid: tcp addr: 0:0:0:0:0:0:0:0.8.1, owner: eric
2021-05-19 11:15:11.293 [] [main] DEBUG o.d.o.p.RpcbindV4Client - portmap set port: prog: 100003 vers: 3, netid: tcp6 addr: 0:0:0:0:0:0:0:0.8.1, owner: eric
2021-05-19 11:15:11.294 [] [main] DEBUG o.d.o.p.RpcbindV4Client - portmap set port: prog: 100003 vers: 4, netid: tcp addr: 0:0:0:0:0:0:0:0.8.1, owner: eric
2021-05-19 11:15:11.294 [] [main] DEBUG o.d.o.p.RpcbindV4Client - portmap set port: prog: 100003 vers: 4, netid: tcp6 addr: 0:0:0:0:0:0:0:0.8.1, owner: eric
2021-05-19 11:15:11.295 [] [main] DEBUG o.d.o.p.RpcbindV4Client - portmap set port: prog: 100005 vers: 3, netid: tcp addr: 0:0:0:0:0:0:0:0.8.1, owner: eric
2021-05-19 11:15:11.295 [] [main] DEBUG o.d.o.p.RpcbindV4Client - portmap set port: prog: 100005 vers: 3, netid: tcp6 addr: 0:0:0:0:0:0:0:0.8.1, owner: eric
2021-05-19 11:15:42.772 [] [nfs4j@2049(2) SelectorRunner] DEBUG o.d.o.r.RpcDispatcher - processing request RPCv2 call: program=100003, version=4, procedure=0
2021-05-19 11:15:42.773 [] [nfs4j@2049 (0)] DEBUG o.d.n.v.NFSServerV41 - NFS PING client: /127.0.0.1:862
2021-05-19 11:15:42.777 [] [nfs4j@2049(3) SelectorRunner] DEBUG o.d.o.r.RpcDispatcher - processing request RPCv2 call: program=100003, version=4, procedure=0
2021-05-19 11:15:42.778 [] [nfs4j@2049 (1)] DEBUG o.d.n.v.NFSServerV41 - NFS PING client: /127.0.0.1:44662
2021-05-19 11:15:42.779 [] [nfs4j@2049(4) SelectorRunner] DEBUG o.d.o.r.RpcDispatcher - processing request RPCv2 call: program=100003, version=4, procedure=0
2021-05-19 11:15:42.779 [] [nfs4j@2049 (2)] DEBUG o.d.n.v.NFSServerV41 - NFS PING client: /127.0.0.1:44664
2021-05-19 11:15:42.781 [] [nfs4j@2049(5) SelectorRunner] DEBUG o.d.o.r.RpcDispatcher - processing request RPCv2 call: program=100003, version=4, procedure=0
2021-05-19 11:15:42.781 [] [nfs4j@2049 (3)] DEBUG o.d.n.v.NFSServerV41 - NFS PING client: /127.0.0.1:44666
2021-05-19 11:15:42.782 [] [nfs4j@2049(6) SelectorRunner] DEBUG o.d.o.r.RpcDispatcher - processing request RPCv2 call: program=100003, version=4, procedure=0
2021-05-19 11:15:42.783 [] [nfs4j@2049 (4)] DEBUG o.d.n.v.NFSServerV41 - NFS PING client: /127.0.0.1:44668
2021-05-19 11:15:42.784 [] [nfs4j@2049(7) SelectorRunner] DEBUG o.d.o.r.RpcDispatcher - processing request RPCv2 call: program=100003, version=4, procedure=0
2021-05-19 11:15:42.785 [] [nfs4j@2049 (5)] DEBUG o.d.n.v.NFSServerV41 - NFS PING client: /127.0.0.1:44670
2021-05-19 11:15:42.786 [] [nfs4j@2049(8) SelectorRunner] DEBUG o.d.o.r.RpcDispatcher - processing request RPCv2 call: program=100003, version=4, procedure=0
2021-05-19 11:15:42.787 [] [nfs4j@2049 (6)] DEBUG o.d.n.v.NFSServerV41 - NFS PING client: /127.0.0.1:44672
2021-05-19 11:15:42.788 [] [nfs4j@2049(9) SelectorRunner] DEBUG o.d.o.r.RpcDispatcher - processing request RPCv2 call: program=100003, version=4, procedure=0
2021-05-19 11:15:42.789 [] [nfs4j@2049 (7)] DEBUG o.d.n.v.NFSServerV41 - NFS PING client: /127.0.0.1:44674
2021-05-19 11:15:42.790 [] [nfs4j@2049(10) SelectorRunner] DEBUG o.d.o.r.RpcDispatcher - processing request RPCv2 call: program=100003, version=4, procedure=0
2021-05-19 11:15:42.791 [] [nfs4j@2049 (8)] DEBUG o.d.n.v.NFSServerV41 - NFS PING client: /127.0.0.1:44676
2021-05-19 11:15:42.792 [] [nfs4j@2049(2) SelectorRunner] DEBUG o.d.o.r.RpcDispatcher - processing request RPCv2 call: program=100003, version=4, procedure=1
2021-05-19 11:15:42.794 [/127.0.0.1:862] [nfs4j@2049 (9)] DEBUG o.d.n.v.NFSServerV41 - NFS COMPOUND client: /127.0.0.1:862, tag: []
2021-05-19 11:15:42.802 [/127.0.0.1:862] [nfs4j@2049 (9)] DEBUG o.d.n.v.OperationEXCHANGE_ID - Case 1: New Owner ID
2021-05-19 11:15:42.803 [/127.0.0.1:862] [nfs4j@2049 (9)] DEBUG o.d.n.v.NFS4Client - New client: /127.0.0.1:862:4c696e7578204e465376342e3120736572766572@6963943046991839233:v4.1
2021-05-19 11:15:42.806 [/127.0.0.1:862] [nfs4j@2049 (9)] DEBUG o.d.utils.Cache - Adding new cache entry: key = [6963943046991839233], value = [/127.0.0.1:862:4c696e7578204e465376342e3120736572766572@6963943046991839233:v4.1]
2021-05-19 11:15:42.808 [/127.0.0.1:862] [nfs4j@2049 (9)] DEBUG o.d.n.v.NFSServerV41 - OP: [] status: 0
2021-05-19 11:15:42.809 [] [nfs4j@2049(2) SelectorRunner] DEBUG o.d.o.r.RpcDispatcher - processing request RPCv2 call: program=100003, version=4, procedure=1
2021-05-19 11:15:42.810 [/127.0.0.1:862] [nfs4j@2049 (10)] DEBUG o.d.n.v.NFSServerV41 - NFS COMPOUND client: /127.0.0.1:862, tag: []
2021-05-19 11:15:42.811 [/127.0.0.1:862] [nfs4j@2049 (10)] DEBUG o.d.n.v.OperationEXCHANGE_ID - case 4: Replacement of Unconfirmed Record
2021-05-19 11:15:42.811 [/127.0.0.1:862] [nfs4j@2049 (10)] DEBUG o.d.utils.Cache - Removing entry: active = [true] key = [6963943046991839233], value = [/127.0.0.1:862:4c696e7578204e465376342e3120736572766572@6963943046991839233:v4.1]
2021-05-19 11:15:42.811 [/127.0.0.1:862] [nfs4j@2049 (10)] DEBUG o.d.n.v.NFS4Client - New client: /127.0.0.1:862:4c696e7578204e465376342e3120736572766572@6963943046991839234:v4.1
2021-05-19 11:15:42.811 [/127.0.0.1:862] [nfs4j@2049 (10)] DEBUG o.d.utils.Cache - Adding new cache entry: key = [6963943046991839234], value = [/127.0.0.1:862:4c696e7578204e465376342e3120736572766572@6963943046991839234:v4.1]
2021-05-19 11:15:42.811 [/127.0.0.1:862] [nfs4j@2049 (10)] DEBUG o.d.n.v.NFSServerV41 - OP: [] status: 0
2021-05-19 11:15:42.811 [] [nfs4j@2049(2) SelectorRunner] DEBUG o.d.o.r.RpcDispatcher - processing request RPCv2 call: program=100003, version=4, procedure=1
2021-05-19 11:15:42.812 [/127.0.0.1:862] [nfs4j@2049 (11)] DEBUG o.d.n.v.NFSServerV41 - NFS COMPOUND client: /127.0.0.1:862, tag: []
2021-05-19 11:15:42.813 [/127.0.0.1:862] [nfs4j@2049 (11)] DEBUG o.d.utils.Cache - Cache hits for key = [6963943046991839234], value = [/127.0.0.1:862:4c696e7578204e465376342e3120736572766572@6963943046991839234:v4.1]
2021-05-19 11:15:42.813 [/127.0.0.1:862] [nfs4j@2049 (11)] DEBUG o.d.n.v.NFS4Client - session for sequience: 1
2021-05-19 11:15:42.814 [/127.0.0.1:862] [nfs4j@2049 (11)] DEBUG o.d.n.v.NFS4Client - set client confirmed
2021-05-19 11:15:42.814 [/127.0.0.1:862] [nfs4j@2049 (11)] DEBUG o.d.n.v.OperationCREATE_SESSION - adding new session [/127.0.0.1:862 : 60a4e54e000000020000000000000001]
2021-05-19 11:15:42.815 [/127.0.0.1:862] [nfs4j@2049 (11)] DEBUG o.d.n.v.NFSServerV41 - OP: [] status: 0
2021-05-19 11:15:42.816 [] [nfs4j@2049(2) SelectorRunner] DEBUG o.d.o.r.RpcDispatcher - processing request RPCv2 call: program=100003, version=4, procedure=1
2021-05-19 11:15:42.816 [/127.0.0.1:862] [nfs4j@2049 (12)] DEBUG o.d.n.v.NFSServerV41 - NFS COMPOUND client: /127.0.0.1:862, tag: []
2021-05-19 11:15:42.817 [/127.0.0.1:862] [nfs4j@2049 (12)] DEBUG o.d.utils.Cache - Cache hits for key = [6963943046991839234], value = [/127.0.0.1:862:4c696e7578204e465376342e3120736572766572@6963943046991839234:v4.1]
2021-05-19 11:15:42.818 [/127.0.0.1:862] [nfs4j@2049 (12)] DEBUG o.d.n.v.NFSServerV41 - OP: [] status: 0
2021-05-19 11:15:42.819 [] [nfs4j@2049(11) SelectorRunner] DEBUG o.d.o.r.RpcDispatcher - processing request RPCv2 call: program=100003, version=4, procedure=0
2021-05-19 11:15:42.819 [] [nfs4j@2049 (13)] DEBUG o.d.n.v.NFSServerV41 - NFS PING client: /127.0.0.1:44678
2021-05-19 11:15:42.820 [] [nfs4j@2049(12) SelectorRunner] DEBUG o.d.o.r.RpcDispatcher - processing request RPCv2 call: program=100003, version=4, procedure=0
2021-05-19 11:15:42.821 [] [nfs4j@2049 (14)] DEBUG o.d.n.v.NFSServerV41 - NFS PING client: /127.0.0.1:44680
2021-05-19 11:15:42.854 [] [nfs4j@2049(2) SelectorRunner] DEBUG o.d.o.r.RpcDispatcher - processing request RPCv2 call: program=100003, version=4, procedure=1
2021-05-19 11:15:42.855 [/127.0.0.1:862] [nfs4j@2049 (15)] DEBUG o.d.n.v.NFSServerV41 - NFS COMPOUND client: /127.0.0.1:862, tag: []
2021-05-19 11:15:42.856 [/127.0.0.1:862] [nfs4j@2049 (15)] DEBUG o.d.utils.Cache - Cache hits for key = [6963943046991839234], value = [/127.0.0.1:862:4c696e7578204e465376342e3120736572766572@6963943046991839234:v4.1]
2021-05-19 11:15:42.856 [/127.0.0.1:862] [nfs4j@2049 (15)] DEBUG o.d.n.v.NFSServerV41 - OP: [] status: 0
2021-05-19 11:15:42.857 [] [nfs4j@2049(2) SelectorRunner] DEBUG o.d.o.r.RpcDispatcher - processing request RPCv2 call: program=100003, version=4, procedure=1
2021-05-19 11:15:42.858 [/127.0.0.1:862] [nfs4j@2049 (16)] DEBUG o.d.n.v.NFSServerV41 - NFS COMPOUND client: /127.0.0.1:862, tag: []
2021-05-19 11:15:42.858 [/127.0.0.1:862] [nfs4j@2049 (16)] DEBUG o.d.utils.Cache - Cache hits for key = [6963943046991839234], value = [/127.0.0.1:862:4c696e7578204e465376342e3120736572766572@6963943046991839234:v4.1]
2021-05-19 11:15:42.859 [/127.0.0.1:862] [nfs4j@2049 (16)] DEBUG o.d.utils.Cache - Removing entry: active = [true] key = [6963943046991839234], value = [/127.0.0.1:862:4c696e7578204e465376342e3120736572766572@6963943046991839234:v4.1]
2021-05-19 11:15:42.859 [/127.0.0.1:862] [nfs4j@2049 (16)] DEBUG o.d.n.v.NFSServerV41 - OP: [] status: 0
Must be something stupid but I'm stuck on it. What could I have missed ?
Thanks
question