* Problems using sec=krb5 with also sec=sys in any share [not found] <1814327585.428221288089705648.JavaMail.root@spooler8-g27.priv.proxad.net> @ 2010-10-26 12:08 ` arnaud.desmier 0 siblings, 0 replies; 3+ messages in thread From: arnaud.desmier @ 2010-10-26 12:08 UTC (permalink / raw) To: linux-nfs Hi all, I'm trying to share some folders like /home and /var/mail with differents security flavors between some machines in a virtual network using VirtualBox. My virtual network is compunded of : - my NFS server, also called nashome, IP address : 192.168.10.5. It's a Debian Squeeze Virtual Machine, using nfs-utils 1.2.2 - my email server, also called servicesext (external services), IP address : 10.1.2.10. It's a Debian Squeeze Virtual Machine, using nfs-utils 1.2.2 - my kerberos (MIT) server, also called serviceint (internal services), IP address : 192.168.10.4. It's a Debian Squeeze Virtual Machine - my user computer, also called posteA, IP address : 192.168.10.50. It's an Ubuntu 10.10 NFS shared folders constraints are following : - /home must be accessed using kerberos identification, I have to mount it on servicesext and posteA - /var/mail is filled by exim4 so I can't use kerberos authentication, only sys flavor, I have to mount it on servicesext only /export/home and /export/mail are bind mount : mount --bind /var/mail/ /export/mail/ mount --bind /home /export/home/ All Squeeze machines have been updated at the same time and tests have reproduced using nfs-utils 1.2.2 with and without debian patches, and also with nfs-utils 1.2.3. Each time the same result. 1. Each time, when a share folder is set with sec=krb5 as security flavor, client is blocked and mount command never ends. For example (/etc/exports) : /export -fsid=0,insecure,no_subtree_check 10.1.2.10(sec=sys:krb5) 192.168.10.50(sec=krb5) /export/home -sec=krb5,rw,nohide,insecure,no_subtree_check 192.168.10.50 10.1.2.10 /export/mail -sec=sys,rw,nohide,insecure,no_subtree_check 10.1.2.10 - Using my servicesext (10.1.2.10) machine, I can mount nashome:/mail : # umount /mnt/nfs4; mount -t nfs4 nashome:/mail /mnt/nfs4 -vvvv - but when I try to mount nashome:/home, mount command never ends (see logs below) # umount /mnt/nfs4; mount -t nfs4 -o sec=krb5 nashome:/home /mnt/nfs4 -vvvv 2. Instead of using sec=krb5, I will use old expression gss/krb5 : the following does not work /export -fsid=0,insecure,no_subtree_check 10.1.2.10(sec=sys:krb5) 192.168.10.50(sec=krb5) gss/krb5 /export/home -sec=krb5,rw,nohide,insecure,no_subtree_check 192.168.10.50 10.1.2.10 gss/krb5 /export/mail -sec=sys,rw,nohide,insecure,no_subtree_check 10.1.2.10 3. And an amazing thing, if I remove all authentications except gss/krb5 I can mount nashome:/home (see logs below). Mounting on posteA works only if I remove it's IP address 192.168.10.50 from second line. /export -fsid=0,insecure,no_subtree_check gss/krb5 /export/home -rw,nohide,insecure,no_subtree_check 192.168.10.50 gss/krb5 #/export/mail -sec=sys,rw,nohide,insecure,no_subtree_check 10.1.2.10 Following are logs files for mount and syslog on servicesext, nashome syslog, and servicesint Kerberos KDC logs for step 1 when mounting nashome:/home - mount logs : 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: "nashome:/home" mount: node: "/mnt/nfs4" mount: types: "nfs4" mount: opts: "sec=krb5" mount: external mount: argv[0] = "/sbin/mount.nfs4" mount: external mount: argv[1] = "nashome:/home" mount: external mount: argv[2] = "/mnt/nfs4" 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 Tue Oct 26 12:06:40 2010 mount.nfs4: trying text-based options 'sec=krb5,addr=192.168.10.5,clientaddr=10.1.2.10' - Servicesext syslog : Oct 26 12:04:40 servicesext rpc.idmapd[587]: New client: 0 Oct 26 12:04:40 servicesext rpc.idmapd[587]: Opened /var/lib/nfs/rpc_pipefs/nfs/clnt0/idmap Oct 26 12:04:40 servicesext rpc.idmapd[587]: New client: 1 Oct 26 12:04:40 servicesext rpc.gssd[591]: handling gssd upcall (/var/lib/nfs/rpc_pipefs/nfs/clnt0) Oct 26 12:04:40 servicesext rpc.gssd[591]: handle_gssd_upcall: 'mech=krb5 uid=0 ' Oct 26 12:04:40 servicesext rpc.gssd[591]: handling krb5 upcall (/var/lib/nfs/rpc_pipefs/nfs/clnt0) Oct 26 12:04:40 servicesext rpc.gssd[591]: process_krb5_upcall: service is '<null>' Oct 26 12:04:40 servicesext rpc.gssd[591]: Full hostname for 'nashome.desmier.org' is 'nashome.desmier.org' Oct 26 12:04:40 servicesext rpc.gssd[591]: Full hostname for 'servicesext.desmier.org' is 'servicesext.desmier.org' Oct 26 12:04:40 servicesext rpc.gssd[591]: Key table entry not found while getting keytab entry for 'root/servicesext.desmier.org@DESMIER.ORG' Oct 26 12:04:40 servicesext rpc.gssd[591]: Success getting keytab entry for 'nfs/servicesext.desmier.org@DESMIER.ORG' Oct 26 12:04:40 servicesext rpc.gssd[591]: Successfully obtained machine credentials for principal 'nfs/servicesext.desmier.org@DESMIER.ORG' stored in ccache 'FILE:/tmp/krb5cc_machine_DESMIER.ORG' Oct 26 12:04:40 servicesext rpc.gssd[591]: INFO: Credentials in CC 'FILE:/tmp/krb5cc_machine_DESMIER.ORG' are good until 1288123449 Oct 26 12:04:40 servicesext rpc.gssd[591]: using FILE:/tmp/krb5cc_machine_DESMIER.ORG as credentials cache for machine creds Oct 26 12:04:40 servicesext rpc.gssd[591]: using environment variable to select krb5 ccache FILE:/tmp/krb5cc_machine_DESMIER.ORG Oct 26 12:04:40 servicesext rpc.gssd[591]: creating context using fsuid 0 (save_uid 0) Oct 26 12:04:40 servicesext rpc.gssd[591]: creating tcp client for server nashome.desmier.org Oct 26 12:04:40 servicesext rpc.gssd[591]: DEBUG: port already set to 2049 Oct 26 12:04:40 servicesext rpc.gssd[591]: creating context with server nfs@nashome.desmier.org Oct 26 12:04:40 servicesext rpc.gssd[591]: in authgss_create_default() Oct 26 12:04:40 servicesext rpc.gssd[591]: in authgss_create() Oct 26 12:04:40 servicesext rpc.gssd[591]: authgss_create: name is 0xa047908 Oct 26 12:04:40 servicesext rpc.gssd[591]: authgss_create: gd->name is 0xa047e38 Oct 26 12:04:40 servicesext rpc.gssd[591]: in authgss_refresh() Oct 26 12:04:40 servicesext rpc.gssd[591]: struct rpc_gss_sec: Oct 26 12:04:40 servicesext rpc.gssd[591]: mechanism_OID: { 1 2 134 72 134 247 18 1 2 2 } Oct 26 12:04:40 servicesext rpc.gssd[591]: qop: 0 Oct 26 12:04:40 servicesext rpc.gssd[591]: service: 1 Oct 26 12:04:40 servicesext rpc.gssd[591]: cred: 0xa047c10 Oct 26 12:04:40 servicesext rpc.gssd[591]: req_flags: 00000002 Oct 26 12:04:40 servicesext rpc.gssd[591]: in authgss_marshal() Oct 26 12:04:40 servicesext rpc.gssd[591]: xdr_rpc_gss_buf: encode success ((nil):0) Oct 26 12:04:40 servicesext rpc.gssd[591]: xdr_rpc_gss_cred: encode success (v 1, proc 1, seq 0, svc 1, ctx (nil):0) Oct 26 12:04:40 servicesext rpc.gssd[591]: xdr_rpc_gss_buf: encode success (0xa04b410:586) Oct 26 12:04:40 servicesext rpc.gssd[591]: xdr_rpc_gss_init_args: encode success (token 0xa04b410:586) Oct 26 12:04:40 servicesext rpc.gssd[591]: in authgss_validate() Oct 26 12:04:40 servicesext rpc.gssd[591]: xdr_rpc_gss_buf: decode success (0xa047440:4) Oct 26 12:04:40 servicesext rpc.gssd[591]: xdr_rpc_gss_buf: decode success (0xa04b660:114) Oct 26 12:04:40 servicesext rpc.gssd[591]: xdr_rpc_gss_init_res decode success (ctx 0xa047440:4, maj 0, min 0, win 128, token 0xa04b660:114) Oct 26 12:04:40 servicesext rpc.gssd[591]: authgss_create_default: freeing name 0xa047908 Oct 26 12:04:40 servicesext rpc.gssd[591]: in authgss_get_private_data() Oct 26 12:04:40 servicesext rpc.gssd[591]: DEBUG: serialize_krb5_ctx: lucid version! Oct 26 12:04:40 servicesext rpc.gssd[591]: prepare_krb5_rfc1964_buffer: serializing keys with enctype 4 and length 8 Oct 26 12:04:40 servicesext rpc.gssd[591]: doing downcall Oct 26 12:04:40 servicesext rpc.gssd[591]: in authgss_free_private_data() Oct 26 12:04:40 servicesext rpc.gssd[591]: in authgss_destroy() Oct 26 12:04:40 servicesext rpc.gssd[591]: in authgss_destroy_context() Oct 26 12:04:40 servicesext rpc.gssd[591]: authgss_destroy: freeing name 0xa047e38 Oct 26 12:07:40 servicesext kernel: [ 231.993067] nfs: server nashome not responding, still trying - When I kill mount with Ctrl+C : Oct 26 12:22:13 servicesext rpc.idmapd[587]: Stale client: 1 Oct 26 12:22:13 servicesext rpc.idmapd[587]: #011-> closed /var/lib/nfs/rpc_pipefs/nfs/clnt1/idmap Oct 26 12:22:13 servicesext rpc.idmapd[587]: Stale client: 0 Oct 26 12:22:13 servicesext rpc.idmapd[587]: #011-> closed /var/lib/nfs/rpc_pipefs/nfs/clnt0/idmap Oct 26 12:22:13 servicesext rpc.gssd[591]: destroying client /var/lib/nfs/rpc_pipefs/nfs/clnt1 Oct 26 12:22:13 servicesext rpc.gssd[591]: destroying client /var/lib/nfs/rpc_pipefs/nfs/clnt0 - Nashome syslog : Oct 26 12:04:09 nashome rpc.svcgssd[2775]: leaving poll Oct 26 12:04:09 nashome rpc.svcgssd[2775]: handling null request Oct 26 12:04:09 nashome rpc.svcgssd[2775]: sname = nfs/servicesext.desmier.org@DESMIER.ORG Oct 26 12:04:09 nashome rpc.svcgssd[2775]: DEBUG: serialize_krb5_ctx: lucid version! Oct 26 12:04:09 nashome rpc.svcgssd[2775]: prepare_krb5_rfc1964_buffer: serializing keys with enctype 4 and length 8 Oct 26 12:04:09 nashome rpc.svcgssd[2775]: doing downcall Oct 26 12:04:09 nashome rpc.svcgssd[2775]: mech: krb5, hndl len: 4, ctx len 85, timeout: 1288123449 (36000 from now), clnt: nfs@servicesext.desmier.org, uid: -1, gid: -1, num aux grps: 0: Oct 26 12:04:09 nashome rpc.svcgssd[2775]: sending null reply Oct 26 12:04:09 nashome rpc.svcgssd[2775]: writing message: \x \x6082024606092a864886f71201020201006e82023530820231a003020105a10302010ea20703050020000000a38201596182015530820151a003020105a10d1b0b4445534d4945522e4f5247a2253023a003020103a11c301a1b036e66731b136e6173686f6d652e6465736d6965722e6f7267a38201123082010ea003020112a103020107a28201000481fdd265dab6ac3f0baf6338d64153d32b4873c93c166b66eff6cb7b48e85f13a24d21fc7d0fb94e76cc14df4d4d2291588b7759fb497d2c23c622f9dd1da834a97c0a2027e075444a846f63747d375b6db9ad5aae106e639703653bec4e7a8e06f6dcbd1d3c03305fb3b01d84024697e2cfa34277d15ec1b96c164d344ca00444335ccefdcdf275ab6cb6767adf1d2706b9f0ce32d6bde3e9729e807dd4471531b1f96a31dda0be6938782724b7e72983c7ae796abeac1ddec8fab06e486bbab2c5c5fe789b93fa3eabc994142920ba4b725c2266bd615c08f4d603748fb568ff7f921105a379425fcff276db52560e53198faf29ba55345951d89b322318a481be3081bba003020101a281b30481b0be97d17110d6ca7d64716a301d5b741256068040fa844a607613cb8fc1235774c3a4fbe5669fdc8edcf92af25a6651cdd8cb11b4! fccf06affbe76e4d9905d8cfa1c6202990b3471895f37ff1ba5d5caf9d7980c2b0a7fffe67e0f9c2b7929d10488034727b013e725abae91fce125d1fae14f0959e714442e459f0868db3af26b395386f854fcb450d5889321250a75a0f142dcfb721e244aa2233e269d65e9f1f20a1350f691765210c2eb7ddfcab78 1288087509 0 0 \x02000000 \x607006092a864886f71201020202006f61305fa003020105a10302010fa2533051a003020101a24a0448cdd3980ca17e39234e4b5f8d0ed3295cf4716a92830ae3d61fa5716d69d41cf6d5d6e676e0a35ef1d02bd1014fb6191846add36ae5b15b2e820f23f4ccaceb4ec63431bb0df9dcbe Oct 26 12:04:09 nashome rpc.svcgssd[2775]: finished handling null request Oct 26 12:04:09 nashome rpc.svcgssd[2775]: entering poll - servicesint Kerberos KDC logs : Oct 26 12:04:09 servicesint krb5kdc[1000](info): AS_REQ (7 etypes {18 17 16 23 1 3 2}) 10.1.2.10: NEEDED_PREAUTH: nfs/servicesext.desmier.org@DESMIER.ORG for krbtgt/DESMIER.ORG@DESMIER.ORG, Additional pre-authentication required Oct 26 12:04:09 servicesint krb5kdc[1000](info): AS_REQ (7 etypes {18 17 16 23 1 3 2}) 10.1.2.10: ISSUE: authtime 1288087449, etypes {rep=18 tkt=18 ses=18}, nfs/servicesext.desmier.org@DESMIER.ORG for krbtgt/DESMIER.ORG@DESMIER.ORG Oct 26 12:04:09 servicesint krb5kdc[1000](info): TGS_REQ (7 etypes {18 17 16 23 1 3 2}) 10.1.2.10: ISSUE: authtime 1288087449, etypes {rep=18 tkt=18 ses=18}, nfs/servicesext.desmier.org@DESMIER.ORG for nfs/nashome.desmier.org@DESMIER.ORG Oct 26 12:04:09 servicesint krb5kdc[1000](info): TGS_REQ (3 etypes {1 3 2}) 10.1.2.10: ISSUE: authtime 1288087449, etypes {rep=18 tkt=18 ses=1}, nfs/servicesext.desmier.org@DESMIER.ORG for nfs/nashome.desmier.org@DESMIER.ORG Following are logs files for mount and syslog on servicesext, nashome syslog, and servicesint Kerberos KDC logs for step 3 when mounting nashome:/home - Servicesext mount logs : 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: "nashome:/home" mount: node: "/mnt/nfs4" mount: types: "nfs4" mount: opts: "sec=krb5" mount: external mount: argv[0] = "/sbin/mount.nfs4" mount: external mount: argv[1] = "nashome:/home" mount: external mount: argv[2] = "/mnt/nfs4" 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 Tue Oct 26 12:25:02 2010 mount.nfs4: trying text-based options 'sec=krb5,addr=192.168.10.5,clientaddr=10.1.2.10' nashome:/home on /mnt/nfs4 type nfs4 (rw,sec=krb5) - Servicesext syslog : ct 26 12:23:02 servicesext rpc.idmapd[587]: New client: 2 Oct 26 12:23:02 servicesext rpc.idmapd[587]: Opened /var/lib/nfs/rpc_pipefs/nfs/clnt2/idmap Oct 26 12:23:02 servicesext rpc.gssd[591]: handling gssd upcall (/var/lib/nfs/rpc_pipefs/nfs/clnt2) Oct 26 12:23:02 servicesext rpc.gssd[591]: handle_gssd_upcall: 'mech=krb5 uid=0 ' Oct 26 12:23:02 servicesext rpc.gssd[591]: handling krb5 upcall (/var/lib/nfs/rpc_pipefs/nfs/clnt2) Oct 26 12:23:02 servicesext rpc.gssd[591]: process_krb5_upcall: service is '<null>' Oct 26 12:23:02 servicesext rpc.idmapd[587]: New client: 3 Oct 26 12:23:02 servicesext rpc.gssd[591]: Full hostname for 'nashome.desmier.org' is 'nashome.desmier.org' Oct 26 12:23:02 servicesext rpc.gssd[591]: Full hostname for 'servicesext.desmier.org' is 'servicesext.desmier.org' Oct 26 12:23:02 servicesext rpc.gssd[591]: Key table entry not found while getting keytab entry for 'root/servicesext.desmier.org@DESMIER.ORG' Oct 26 12:23:02 servicesext rpc.gssd[591]: Success getting keytab entry for 'nfs/servicesext.desmier.org@DESMIER.ORG' Oct 26 12:23:02 servicesext rpc.gssd[591]: INFO: Credentials in CC 'FILE:/tmp/krb5cc_machine_DESMIER.ORG' are good until 1288123449 Oct 26 12:23:02 servicesext rpc.gssd[591]: INFO: Credentials in CC 'FILE:/tmp/krb5cc_machine_DESMIER.ORG' are good until 1288123449 Oct 26 12:23:02 servicesext rpc.gssd[591]: using FILE:/tmp/krb5cc_machine_DESMIER.ORG as credentials cache for machine creds Oct 26 12:23:02 servicesext rpc.gssd[591]: using environment variable to select krb5 ccache FILE:/tmp/krb5cc_machine_DESMIER.ORG Oct 26 12:23:02 servicesext rpc.gssd[591]: creating context using fsuid 0 (save_uid 0) Oct 26 12:23:02 servicesext rpc.gssd[591]: creating tcp client for server nashome.desmier.org Oct 26 12:23:02 servicesext rpc.gssd[591]: DEBUG: port already set to 2049 Oct 26 12:23:02 servicesext rpc.gssd[591]: creating context with server nfs@nashome.desmier.org Oct 26 12:23:02 servicesext rpc.gssd[591]: in authgss_create_default() Oct 26 12:23:02 servicesext rpc.gssd[591]: in authgss_create() Oct 26 12:23:02 servicesext rpc.gssd[591]: authgss_create: name is 0xa04b370 Oct 26 12:23:02 servicesext rpc.gssd[591]: authgss_create: gd->name is 0xa047b90 Oct 26 12:23:02 servicesext rpc.gssd[591]: in authgss_refresh() Oct 26 12:23:02 servicesext rpc.gssd[591]: struct rpc_gss_sec: Oct 26 12:23:02 servicesext rpc.gssd[591]: mechanism_OID: { 1 2 134 72 134 247 18 1 2 2 } Oct 26 12:23:02 servicesext rpc.gssd[591]: qop: 0 Oct 26 12:23:02 servicesext rpc.gssd[591]: service: 1 Oct 26 12:23:02 servicesext rpc.gssd[591]: cred: 0xa04b390 Oct 26 12:23:02 servicesext rpc.gssd[591]: req_flags: 00000002 Oct 26 12:23:02 servicesext rpc.gssd[591]: in authgss_marshal() Oct 26 12:23:02 servicesext rpc.gssd[591]: xdr_rpc_gss_buf: encode success ((nil):0) Oct 26 12:23:02 servicesext rpc.gssd[591]: xdr_rpc_gss_cred: encode success (v 1, proc 1, seq 0, svc 1, ctx (nil):0) Oct 26 12:23:02 servicesext rpc.gssd[591]: xdr_rpc_gss_buf: encode success (0xa04a1f0:586) Oct 26 12:23:02 servicesext rpc.gssd[591]: xdr_rpc_gss_init_args: encode success (token 0xa04a1f0:586) Oct 26 12:23:02 servicesext rpc.gssd[591]: in authgss_validate() Oct 26 12:23:02 servicesext rpc.gssd[591]: xdr_rpc_gss_buf: decode success (0xa04c428:4) Oct 26 12:23:02 servicesext rpc.gssd[591]: xdr_rpc_gss_buf: decode success (0xa04b068:114) Oct 26 12:23:02 servicesext rpc.gssd[591]: xdr_rpc_gss_init_res decode success (ctx 0xa04c428:4, maj 0, min 0, win 128, token 0xa04b068:114) Oct 26 12:23:02 servicesext rpc.gssd[591]: authgss_create_default: freeing name 0xa04b370 Oct 26 12:23:02 servicesext rpc.gssd[591]: in authgss_get_private_data() Oct 26 12:23:02 servicesext rpc.gssd[591]: DEBUG: serialize_krb5_ctx: lucid version! Oct 26 12:23:02 servicesext rpc.gssd[591]: prepare_krb5_rfc1964_buffer: serializing keys with enctype 4 and length 8 Oct 26 12:23:02 servicesext rpc.gssd[591]: doing downcall Oct 26 12:23:02 servicesext rpc.gssd[591]: in authgss_free_private_data() Oct 26 12:23:02 servicesext rpc.gssd[591]: in authgss_destroy() Oct 26 12:23:02 servicesext rpc.gssd[591]: in authgss_destroy_context() Oct 26 12:23:02 servicesext rpc.gssd[591]: authgss_destroy: freeing name 0xa047b90 Oct 26 12:23:02 servicesext rpc.idmapd[587]: nfs4_name_to_uid: calling nsswitch->name_to_uid Oct 26 12:23:02 servicesext rpc.idmapd[587]: nss_getpwnam: name 'root@desmier.org' domain 'desmier.org': resulting localname 'root' Oct 26 12:23:02 servicesext rpc.idmapd[587]: nfs4_name_to_uid: nsswitch->name_to_uid returned 0 Oct 26 12:23:02 servicesext rpc.idmapd[587]: nfs4_name_to_uid: final return value is 0 Oct 26 12:23:02 servicesext rpc.idmapd[587]: Client 2: (user) name "root@desmier.org" -> id "0" Oct 26 12:23:02 servicesext rpc.idmapd[587]: nfs4_name_to_gid: calling nsswitch->name_to_gid Oct 26 12:23:02 servicesext rpc.idmapd[587]: nfs4_name_to_gid: nsswitch->name_to_gid returned 0 Oct 26 12:23:02 servicesext rpc.idmapd[587]: nfs4_name_to_gid: final return value is 0 Oct 26 12:23:02 servicesext rpc.idmapd[587]: Client 2: (group) name "root@desmier.org" -> id "0" Oct 26 12:23:02 servicesext rpc.idmapd[587]: New client: 4 Oct 26 12:23:02 servicesext rpc.gssd[591]: destroying client /var/lib/nfs/rpc_pipefs/nfs/clnt3 Oct 26 12:23:02 servicesext rpc.idmapd[587]: Stale client: 3 Oct 26 12:23:02 servicesext rpc.idmapd[587]: #011-> closed /var/lib/nfs/rpc_pipefs/nfs/clnt3/idmap - Nashome syslog : Oct 26 12:23:00 nashome rpc.svcgssd[2876]: leaving poll Oct 26 12:23:00 nashome rpc.svcgssd[2876]: handling null request Oct 26 12:23:00 nashome rpc.svcgssd[2876]: sname = nfs/servicesext.desmier.org@DESMIER.ORG Oct 26 12:23:00 nashome rpc.svcgssd[2876]: libnfsidmap: using domain: desmier.org Oct 26 12:23:00 nashome rpc.svcgssd[2876]: libnfsidmap: processing 'Method' list Oct 26 12:23:00 nashome rpc.svcgssd[2876]: libnfsidmap: loaded plugin /usr/lib/libnfsidmap/nsswitch.so for method nsswitch Oct 26 12:23:00 nashome rpc.svcgssd[2876]: DEBUG: serialize_krb5_ctx: lucid version! Oct 26 12:23:00 nashome rpc.svcgssd[2876]: prepare_krb5_rfc1964_buffer: serializing keys with enctype 4 and length 8 Oct 26 12:23:00 nashome rpc.svcgssd[2876]: doing downcall Oct 26 12:23:00 nashome rpc.svcgssd[2876]: mech: krb5, hndl len: 4, ctx len 85, timeout: 1288123449 (34869 from now), clnt: nfs@servicesext.desmier.org, uid: -1, gid: -1, num aux grps: 0: Oct 26 12:23:00 nashome rpc.svcgssd[2876]: sending null reply Oct 26 12:23:00 nashome rpc.svcgssd[2876]: writing message: \x \x6082024606092a864886f71201020201006e82023530820231a003020105a10302010ea20703050020000000a38201596182015530820151a003020105a10d1b0b4445534d4945522e4f5247a2253023a003020103a11c301a1b036e66731b136e6173686f6d652e6465736d6965722e6f7267a38201123082010ea003020112a103020107a28201000481fdd265dab6ac3f0baf6338d64153d32b4873c93c166b66eff6cb7b48e85f13a24d21fc7d0fb94e76cc14df4d4d2291588b7759fb497d2c23c622f9dd1da834a97c0a2027e075444a846f63747d375b6db9ad5aae106e639703653bec4e7a8e06f6dcbd1d3c03305fb3b01d84024697e2cfa34277d15ec1b96c164d344ca00444335ccefdcdf275ab6cb6767adf1d2706b9f0ce32d6bde3e9729e807dd4471531b1f96a31dda0be6938782724b7e72983c7ae796abeac1ddec8fab06e486bbab2c5c5fe789b93fa3eabc994142920ba4b725c2266bd615c08f4d603748fb568ff7f921105a379425fcff276db52560e53198faf29ba55345951d89b322318a481be3081bba003020101a281b30481b0e668f43c88a2cfa3307744065a47b7700539eb9e9d10599ec1a2256f299d4aea4a8ebcf2d48d42bcd3a5625e3b5d567d14b22b5c! bf8a39c1e222ac02681248525b0053ea2ea29f1fb43d9d1c7cac3c6597569b402b0c902450fba2395b29dd99d036fe8c4d124fbcc955e465af1f9c65ba111e6c5116e2806e12b06a8ba507ec84c18a2f8a3622da83a100f91021338cfd2e4f7534f91884af1995d76363d2527e020b88527015ac8a8667324895778d 1288088640 0 0 \x01000000 \x607006092a864886f71201020202006f61305fa003020105a10302010fa2533051a003020101a24a04481c649c866a6c25d3dd3cd5624ccdf9dd26b53134870418ef7137c6da82a5d4da90573edec195a852395593fd4fda7179cb0e40d3481544807d982e25aadc80b3e42e25734dcefeb8 Oct 26 12:23:00 nashome rpc.svcgssd[2876]: finished handling null request Oct 26 12:23:00 nashome rpc.svcgssd[2876]: entering poll Oct 26 12:23:00 nashome rpc.idmapd[2821]: nfsdcb: authbuf=gss/krb5 authtype=user Oct 26 12:23:00 nashome rpc.idmapd[2821]: Server: (user) id "0" -> name "root@desmier.org" Oct 26 12:23:00 nashome rpc.idmapd[2821]: nfsdcb: authbuf=gss/krb5 authtype=group Oct 26 12:23:00 nashome rpc.idmapd[2821]: Server: (group) id "0" -> name "root@desmier.org" - servicesint Kerberos KDC logs : nothing new, credentials are in cache. Did someone already encountered that kind of problem? I've tried a lot tutorials in internet but each time when I use a security flavor like sys with an other share with gss/krb5, mount command never ends when mounting gss/krb5 share. Following /etc/exports doesn't work unless I remove the first line. Once the first line removed, I can mount using krb5[i][p] security flavor. /export *(rw,fsid=0,insecure,no_subtree_check) /export gss/krb5(rw,fsid=0,insecure,no_subtree_check) /export gss/krb5i(rw,fsid=0,insecure,no_subtree_check) /export gss/krb5p(rw,fsid=0,insecure,no_subtree_check) Thanks for any help, advices, best practices, tips... Arnaud ^ permalink raw reply [flat|nested] 3+ messages in thread
[parent not found: <1215084548.814871288266525238.JavaMail.root@spooler8-g27.priv.proxad.net>]
[parent not found: <1215084548.814871288266525238.JavaMail.root-x5ewXQG5twBsFmKuirFwRhh1pbbyJDp15NbjCUgZEJk@public.gmane.org>]
* Re: Problems using sec=krb5 with also sec=sys in any share [not found] ` <1215084548.814871288266525238.JavaMail.root-x5ewXQG5twBsFmKuirFwRhh1pbbyJDp15NbjCUgZEJk@public.gmane.org> @ 2010-10-28 11:49 ` arnaud.desmier 2010-11-16 19:15 ` J. Bruce Fields 0 siblings, 1 reply; 3+ messages in thread From: arnaud.desmier @ 2010-10-28 11:49 UTC (permalink / raw) To: linux-nfs No idea about this problem? no one encountered the same problem? Maybe there is an other mailing list for this kind of problem? Thanks, Arnaud ----- Mail Original ----- De: "arnaud desmier" <arnaud.desmier@free.fr> =C3=80: linux-nfs@vger.kernel.org Envoy=C3=A9: Mardi 26 Octobre 2010 14h08:10 GMT +01:00 Amsterdam / Berl= in / Berne / Rome / Stockholm / Vienne Objet: Problems using sec=3Dkrb5 with also sec=3Dsys in any share Hi all, I'm trying to share some folders like /home and /var/mail with differen= ts security flavors between some machines in a virtual network using Vi= rtualBox. My virtual network is compunded of : - my NFS server, also called nashome, IP address : 192.168.10.5. It's = a Debian Squeeze Virtual Machine, using nfs-utils 1.2.2 - my email server, also called servicesext (external services), IP add= ress : 10.1.2.10. It's a Debian Squeeze Virtual Machine, using nfs-util= s 1.2.2 - my kerberos (MIT) server, also called serviceint (internal services)= , IP address : 192.168.10.4. It's a Debian Squeeze Virtual Machine - my user computer, also called posteA, IP address : 192.168.10.50. It= 's an Ubuntu 10.10 NFS shared folders constraints are following : - /home must be accessed using kerberos identification, I have to moun= t it on servicesext and posteA - /var/mail is filled by exim4 so I can't use kerberos authentication,= only sys flavor, I have to mount it on servicesext only /export/home and /export/mail are bind mount :=20 mount --bind /var/mail/ /export/mail/ mount --bind /home /export/home/ All Squeeze machines have been updated at the same time and tests have = reproduced using nfs-utils 1.2.2 with and without debian patches, and a= lso with nfs-utils 1.2.3. Each time the same result. 1. Each time, when a share folder is set with sec=3Dkrb5 as security fl= avor, client is blocked and mount command never ends. For example (/etc= /exports) :=20 /export -fsid=3D0,insecure,no_subtree_check 10.1.2.10(sec=3Dsys:= krb5) 192.168.10.50(sec=3Dkrb5) /export/home -sec=3Dkrb5,rw,nohide,insecure,no_subtree_check 192.168.= 10.50 10.1.2.10 /export/mail -sec=3Dsys,rw,nohide,insecure,no_subtree_check 10.1.2.10 - Using my servicesext (10.1.2.10) machine, I can mount nashome:/mail = : # umount /mnt/nfs4; mount -t nfs4 nashome:/mail /mnt/nfs4 -vvvv - but when I try to mount nashome:/home, mount command never ends (see= logs below) # umount /mnt/nfs4; mount -t nfs4 -o sec=3Dkrb5 nashome:/home /mnt/n= fs4 -vvvv 2. Instead of using sec=3Dkrb5, I will use old expression gss/krb5 : th= e following does not work /export -fsid=3D0,insecure,no_subtree_check 10.1.2.10(sec=3Dsys:= krb5) 192.168.10.50(sec=3Dkrb5) gss/krb5 /export/home -sec=3Dkrb5,rw,nohide,insecure,no_subtree_check 192.168.= 10.50 10.1.2.10 gss/krb5 /export/mail -sec=3Dsys,rw,nohide,insecure,no_subtree_check 10.1.2.10 3. And an amazing thing, if I remove all authentications except gss/krb= 5 I can mount nashome:/home (see logs below). Mounting on posteA works = only if I remove it's IP address 192.168.10.50 from second line. /export -fsid=3D0,insecure,no_subtree_check gss/krb5 /export/home -rw,nohide,insecure,no_subtree_check 192.168.10.50 gss/k= rb5 #/export/mail -sec=3Dsys,rw,nohide,insecure,no_subtree_check 10.1.2.1= 0 =46ollowing are logs files for mount and syslog on servicesext, nashome= syslog, and servicesint Kerberos KDC logs for step 1 when mounting nas= home:/home - mount logs :=20 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: "nashome:/home" mount: node: "/mnt/nfs4" mount: types: "nfs4" mount: opts: "sec=3Dkrb5" mount: external mount: argv[0] =3D "/sbin/mount.nfs4" mount: external mount: argv[1] =3D "nashome:/home" mount: external mount: argv[2] =3D "/mnt/nfs4" mount: external mount: argv[3] =3D "-v" mount: external mount: argv[4] =3D "-o" mount: external mount: argv[5] =3D "rw,sec=3Dkrb5" mount.nfs4: timeout set for Tue Oct 26 12:06:40 2010 mount.nfs4: trying text-based options 'sec=3Dkrb5,addr=3D192.168.10.5,c= lientaddr=3D10.1.2.10' - Servicesext syslog : Oct 26 12:04:40 servicesext rpc.idmapd[587]: New client: 0 Oct 26 12:04:40 servicesext rpc.idmapd[587]: Opened /var/lib/nfs/rpc_pi= pefs/nfs/clnt0/idmap Oct 26 12:04:40 servicesext rpc.idmapd[587]: New client: 1 Oct 26 12:04:40 servicesext rpc.gssd[591]: handling gssd upcall (/var/l= ib/nfs/rpc_pipefs/nfs/clnt0) Oct 26 12:04:40 servicesext rpc.gssd[591]: handle_gssd_upcall: 'mech=3D= krb5 uid=3D0 ' Oct 26 12:04:40 servicesext rpc.gssd[591]: handling krb5 upcall (/var/l= ib/nfs/rpc_pipefs/nfs/clnt0) Oct 26 12:04:40 servicesext rpc.gssd[591]: process_krb5_upcall: service= is '<null>' Oct 26 12:04:40 servicesext rpc.gssd[591]: Full hostname for 'nashome.d= esmier.org' is 'nashome.desmier.org' Oct 26 12:04:40 servicesext rpc.gssd[591]: Full hostname for 'servicese= xt.desmier.org' is 'servicesext.desmier.org' Oct 26 12:04:40 servicesext rpc.gssd[591]: Key table entry not found wh= ile getting keytab entry for 'root/servicesext.desmier.org-HBhUyB7S6INF7rqys1CUDA@public.gmane.org' Oct 26 12:04:40 servicesext rpc.gssd[591]: Success getting keytab entry= for 'nfs/servicesext.desmier.org-HBhUyB7S6INF7rqys1CUDA@public.gmane.org' Oct 26 12:04:40 servicesext rpc.gssd[591]: Successfully obtained machin= e credentials for principal 'nfs/servicesext.desmier.org-HBhUyB7S6INF7rqys1CUDA@public.gmane.org' s= tored in ccache 'FILE:/tmp/krb5cc_machine_DESMIER.ORG' Oct 26 12:04:40 servicesext rpc.gssd[591]: INFO: Credentials in CC 'FIL= E:/tmp/krb5cc_machine_DESMIER.ORG' are good until 1288123449 Oct 26 12:04:40 servicesext rpc.gssd[591]: using FILE:/tmp/krb5cc_machi= ne_DESMIER.ORG as credentials cache for machine creds Oct 26 12:04:40 servicesext rpc.gssd[591]: using environment variable t= o select krb5 ccache FILE:/tmp/krb5cc_machine_DESMIER.ORG Oct 26 12:04:40 servicesext rpc.gssd[591]: creating context using fsuid= 0 (save_uid 0) Oct 26 12:04:40 servicesext rpc.gssd[591]: creating tcp client for serv= er nashome.desmier.org Oct 26 12:04:40 servicesext rpc.gssd[591]: DEBUG: port already set to 2= 049 Oct 26 12:04:40 servicesext rpc.gssd[591]: creating context with server= nfs-51RxAZSjM3jWMF6bZ8oobUB+6BGkLq7r@public.gmane.org Oct 26 12:04:40 servicesext rpc.gssd[591]: in authgss_create_default() Oct 26 12:04:40 servicesext rpc.gssd[591]: in authgss_create() Oct 26 12:04:40 servicesext rpc.gssd[591]: authgss_create: name is 0xa0= 47908 Oct 26 12:04:40 servicesext rpc.gssd[591]: authgss_create: gd->name is = 0xa047e38 Oct 26 12:04:40 servicesext rpc.gssd[591]: in authgss_refresh() Oct 26 12:04:40 servicesext rpc.gssd[591]: struct rpc_gss_sec: Oct 26 12:04:40 servicesext rpc.gssd[591]: mechanism_OID: { 1 2 13= 4 72 134 247 18 1 2 2 } Oct 26 12:04:40 servicesext rpc.gssd[591]: qop: 0 Oct 26 12:04:40 servicesext rpc.gssd[591]: service: 1 Oct 26 12:04:40 servicesext rpc.gssd[591]: cred: 0xa047c10 Oct 26 12:04:40 servicesext rpc.gssd[591]: req_flags: 00000002 Oct 26 12:04:40 servicesext rpc.gssd[591]: in authgss_marshal() Oct 26 12:04:40 servicesext rpc.gssd[591]: xdr_rpc_gss_buf: encode succ= ess ((nil):0) Oct 26 12:04:40 servicesext rpc.gssd[591]: xdr_rpc_gss_cred: encode suc= cess (v 1, proc 1, seq 0, svc 1, ctx (nil):0) Oct 26 12:04:40 servicesext rpc.gssd[591]: xdr_rpc_gss_buf: encode succ= ess (0xa04b410:586) Oct 26 12:04:40 servicesext rpc.gssd[591]: xdr_rpc_gss_init_args: encod= e success (token 0xa04b410:586) Oct 26 12:04:40 servicesext rpc.gssd[591]: in authgss_validate() Oct 26 12:04:40 servicesext rpc.gssd[591]: xdr_rpc_gss_buf: decode succ= ess (0xa047440:4) Oct 26 12:04:40 servicesext rpc.gssd[591]: xdr_rpc_gss_buf: decode succ= ess (0xa04b660:114) Oct 26 12:04:40 servicesext rpc.gssd[591]: xdr_rpc_gss_init_res decode = success (ctx 0xa047440:4, maj 0, min 0, win 128, token 0xa04b660:114) Oct 26 12:04:40 servicesext rpc.gssd[591]: authgss_create_default: free= ing name 0xa047908 Oct 26 12:04:40 servicesext rpc.gssd[591]: in authgss_get_private_data(= ) Oct 26 12:04:40 servicesext rpc.gssd[591]: DEBUG: serialize_krb5_ctx: l= ucid version! Oct 26 12:04:40 servicesext rpc.gssd[591]: prepare_krb5_rfc1964_buffer:= serializing keys with enctype 4 and length 8 Oct 26 12:04:40 servicesext rpc.gssd[591]: doing downcall Oct 26 12:04:40 servicesext rpc.gssd[591]: in authgss_free_private_data= () Oct 26 12:04:40 servicesext rpc.gssd[591]: in authgss_destroy() Oct 26 12:04:40 servicesext rpc.gssd[591]: in authgss_destroy_context() Oct 26 12:04:40 servicesext rpc.gssd[591]: authgss_destroy: freeing nam= e 0xa047e38 Oct 26 12:07:40 servicesext kernel: [ 231.993067] nfs: server nashome = not responding, still trying - When I kill mount with Ctrl+C :=20 Oct 26 12:22:13 servicesext rpc.idmapd[587]: Stale client: 1 Oct 26 12:22:13 servicesext rpc.idmapd[587]: #011-> closed /var/lib/nfs= /rpc_pipefs/nfs/clnt1/idmap Oct 26 12:22:13 servicesext rpc.idmapd[587]: Stale client: 0 Oct 26 12:22:13 servicesext rpc.idmapd[587]: #011-> closed /var/lib/nfs= /rpc_pipefs/nfs/clnt0/idmap Oct 26 12:22:13 servicesext rpc.gssd[591]: destroying client /var/lib/n= fs/rpc_pipefs/nfs/clnt1 Oct 26 12:22:13 servicesext rpc.gssd[591]: destroying client /var/lib/n= fs/rpc_pipefs/nfs/clnt0 - Nashome syslog :=20 Oct 26 12:04:09 nashome rpc.svcgssd[2775]: leaving poll Oct 26 12:04:09 nashome rpc.svcgssd[2775]: handling null request Oct 26 12:04:09 nashome rpc.svcgssd[2775]: sname =3D nfs/servicesext.de= smier.org-HBhUyB7S6INF7rqys1CUDA@public.gmane.org Oct 26 12:04:09 nashome rpc.svcgssd[2775]: DEBUG: serialize_krb5_ctx: l= ucid version! Oct 26 12:04:09 nashome rpc.svcgssd[2775]: prepare_krb5_rfc1964_buffer:= serializing keys with enctype 4 and length 8 Oct 26 12:04:09 nashome rpc.svcgssd[2775]: doing downcall Oct 26 12:04:09 nashome rpc.svcgssd[2775]: mech: krb5, hndl len: 4, ctx= len 85, timeout: 1288123449 (36000 from now), clnt: nfs-fruN6kYK4IH0mRrQNGSQYw@public.gmane.org= smier.org, uid: -1, gid: -1, num aux grps: 0: Oct 26 12:04:09 nashome rpc.svcgssd[2775]: sending null reply Oct 26 12:04:09 nashome rpc.svcgssd[2775]: writing message: \x \x608202= 4606092a864886f71201020201006e82023530820231a003020105a10302010ea207030= 50020000000a38201596182015530820151a003020105a10d1b0b4445534d4945522e4f= 5247a2253023a003020103a11c301a1b036e66731b136e6173686f6d652e6465736d696= 5722e6f7267a38201123082010ea003020112a103020107a28201000481fdd265dab6ac= 3f0baf6338d64153d32b4873c93c166b66eff6cb7b48e85f13a24d21fc7d0fb94e76cc1= 4df4d4d2291588b7759fb497d2c23c622f9dd1da834a97c0a2027e075444a846f63747d= 375b6db9ad5aae106e639703653bec4e7a8e06f6dcbd1d3c03305fb3b01d84024697e2c= fa34277d15ec1b96c164d344ca00444335ccefdcdf275ab6cb6767adf1d2706b9f0ce32= d6bde3e9729e807dd4471531b1f96a31dda0be6938782724b7e72983c7ae796abeac1dd= ec8fab06e486bbab2c5c5fe789b93fa3eabc994142920ba4b725c2266bd615c08f4d603= 748fb568ff7f921105a379425fcff276db52560e53198faf29ba55345951d89b322318a= 481be3081bba003020101a281b30481b0be97d17110d6ca7d64716a301d5b7412560680= 40fa844a607613cb8fc1235774c3a4fbe5669fdc8edcf92af25a6651cdd8cb11b4f ccf06affbe76e4d9905d8cfa1c6202990b3471895f37ff1ba5d5caf9d7980c2b0a7fff= e67e0f9c2b7929d10488034727b013e725abae91fce125d1fae14f0959e714442e459f0= 868db3af26b395386f854fcb450d5889321250a75a0f142dcfb721e244aa2233e269d65= e9f1f20a1350f691765210c2eb7ddfcab78 1288087509 0 0 \x02000000 \x6070060= 92a864886f71201020202006f61305fa003020105a10302010fa2533051a003020101a2= 4a0448cdd3980ca17e39234e4b5f8d0ed3295cf4716a92830ae3d61fa5716d69d41cf6d= 5d6e676e0a35ef1d02bd1014fb6191846add36ae5b15b2e820f23f4ccaceb4ec63431bb= 0df9dcbe=20 Oct 26 12:04:09 nashome rpc.svcgssd[2775]: finished handling null reque= st Oct 26 12:04:09 nashome rpc.svcgssd[2775]: entering poll - servicesint Kerberos KDC logs : Oct 26 12:04:09 servicesint krb5kdc[1000](info): AS_REQ (7 etypes {18 1= 7 16 23 1 3 2}) 10.1.2.10: NEEDED_PREAUTH: nfs/servicesext.desmier.org@= DESMIER.ORG for krbtgt/DESMIER.ORG-HBhUyB7S6INF7rqys1CUDA@public.gmane.org, Additional pre-authenti= cation required Oct 26 12:04:09 servicesint krb5kdc[1000](info): AS_REQ (7 etypes {18 1= 7 16 23 1 3 2}) 10.1.2.10: ISSUE: authtime 1288087449, etypes {rep=3D18= tkt=3D18 ses=3D18}, nfs/servicesext.desmier.org-HBhUyB7S6INF7rqys1CUDA@public.gmane.org for krbtgt= /DESMIER.ORG-HBhUyB7S6INF7rqys1CUDA@public.gmane.org Oct 26 12:04:09 servicesint krb5kdc[1000](info): TGS_REQ (7 etypes {18 = 17 16 23 1 3 2}) 10.1.2.10: ISSUE: authtime 1288087449, etypes {rep=3D1= 8 tkt=3D18 ses=3D18}, nfs/servicesext.desmier.org-HBhUyB7S6INF7rqys1CUDA@public.gmane.org for nfs/n= ashome.desmier.org-HBhUyB7S6INF7rqys1CUDA@public.gmane.org Oct 26 12:04:09 servicesint krb5kdc[1000](info): TGS_REQ (3 etypes {1 3= 2}) 10.1.2.10: ISSUE: authtime 1288087449, etypes {rep=3D18 tkt=3D18 s= es=3D1}, nfs/servicesext.desmier.org-HBhUyB7S6INF7rqys1CUDA@public.gmane.org for nfs/nashome.desmie= r.org-HBhUyB7S6INF7rqys1CUDA@public.gmane.org =46ollowing are logs files for mount and syslog on servicesext, nashome= syslog, and servicesint Kerberos KDC logs for step 3 when mounting nas= home:/home - Servicesext mount logs : 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: "nashome:/home" mount: node: "/mnt/nfs4" mount: types: "nfs4" mount: opts: "sec=3Dkrb5" mount: external mount: argv[0] =3D "/sbin/mount.nfs4" mount: external mount: argv[1] =3D "nashome:/home" mount: external mount: argv[2] =3D "/mnt/nfs4" mount: external mount: argv[3] =3D "-v" mount: external mount: argv[4] =3D "-o" mount: external mount: argv[5] =3D "rw,sec=3Dkrb5" mount.nfs4: timeout set for Tue Oct 26 12:25:02 2010 mount.nfs4: trying text-based options 'sec=3Dkrb5,addr=3D192.168.10.5,c= lientaddr=3D10.1.2.10' nashome:/home on /mnt/nfs4 type nfs4 (rw,sec=3Dkrb5) - Servicesext syslog : ct 26 12:23:02 servicesext rpc.idmapd[587]: New client: 2 Oct 26 12:23:02 servicesext rpc.idmapd[587]: Opened /var/lib/nfs/rpc_pi= pefs/nfs/clnt2/idmap Oct 26 12:23:02 servicesext rpc.gssd[591]: handling gssd upcall (/var/l= ib/nfs/rpc_pipefs/nfs/clnt2) Oct 26 12:23:02 servicesext rpc.gssd[591]: handle_gssd_upcall: 'mech=3D= krb5 uid=3D0 ' Oct 26 12:23:02 servicesext rpc.gssd[591]: handling krb5 upcall (/var/l= ib/nfs/rpc_pipefs/nfs/clnt2) Oct 26 12:23:02 servicesext rpc.gssd[591]: process_krb5_upcall: service= is '<null>' Oct 26 12:23:02 servicesext rpc.idmapd[587]: New client: 3 Oct 26 12:23:02 servicesext rpc.gssd[591]: Full hostname for 'nashome.d= esmier.org' is 'nashome.desmier.org' Oct 26 12:23:02 servicesext rpc.gssd[591]: Full hostname for 'servicese= xt.desmier.org' is 'servicesext.desmier.org' Oct 26 12:23:02 servicesext rpc.gssd[591]: Key table entry not found wh= ile getting keytab entry for 'root/servicesext.desmier.org-HBhUyB7S6INF7rqys1CUDA@public.gmane.org' Oct 26 12:23:02 servicesext rpc.gssd[591]: Success getting keytab entry= for 'nfs/servicesext.desmier.org-HBhUyB7S6INF7rqys1CUDA@public.gmane.org' Oct 26 12:23:02 servicesext rpc.gssd[591]: INFO: Credentials in CC 'FIL= E:/tmp/krb5cc_machine_DESMIER.ORG' are good until 1288123449 Oct 26 12:23:02 servicesext rpc.gssd[591]: INFO: Credentials in CC 'FIL= E:/tmp/krb5cc_machine_DESMIER.ORG' are good until 1288123449 Oct 26 12:23:02 servicesext rpc.gssd[591]: using FILE:/tmp/krb5cc_machi= ne_DESMIER.ORG as credentials cache for machine creds Oct 26 12:23:02 servicesext rpc.gssd[591]: using environment variable t= o select krb5 ccache FILE:/tmp/krb5cc_machine_DESMIER.ORG Oct 26 12:23:02 servicesext rpc.gssd[591]: creating context using fsuid= 0 (save_uid 0) Oct 26 12:23:02 servicesext rpc.gssd[591]: creating tcp client for serv= er nashome.desmier.org Oct 26 12:23:02 servicesext rpc.gssd[591]: DEBUG: port already set to 2= 049 Oct 26 12:23:02 servicesext rpc.gssd[591]: creating context with server= nfs-51RxAZSjM3jWMF6bZ8oobUB+6BGkLq7r@public.gmane.org Oct 26 12:23:02 servicesext rpc.gssd[591]: in authgss_create_default() Oct 26 12:23:02 servicesext rpc.gssd[591]: in authgss_create() Oct 26 12:23:02 servicesext rpc.gssd[591]: authgss_create: name is 0xa0= 4b370 Oct 26 12:23:02 servicesext rpc.gssd[591]: authgss_create: gd->name is = 0xa047b90 Oct 26 12:23:02 servicesext rpc.gssd[591]: in authgss_refresh() Oct 26 12:23:02 servicesext rpc.gssd[591]: struct rpc_gss_sec: Oct 26 12:23:02 servicesext rpc.gssd[591]: mechanism_OID: { 1 2 13= 4 72 134 247 18 1 2 2 } Oct 26 12:23:02 servicesext rpc.gssd[591]: qop: 0 Oct 26 12:23:02 servicesext rpc.gssd[591]: service: 1 Oct 26 12:23:02 servicesext rpc.gssd[591]: cred: 0xa04b390 Oct 26 12:23:02 servicesext rpc.gssd[591]: req_flags: 00000002 Oct 26 12:23:02 servicesext rpc.gssd[591]: in authgss_marshal() Oct 26 12:23:02 servicesext rpc.gssd[591]: xdr_rpc_gss_buf: encode succ= ess ((nil):0) Oct 26 12:23:02 servicesext rpc.gssd[591]: xdr_rpc_gss_cred: encode suc= cess (v 1, proc 1, seq 0, svc 1, ctx (nil):0) Oct 26 12:23:02 servicesext rpc.gssd[591]: xdr_rpc_gss_buf: encode succ= ess (0xa04a1f0:586) Oct 26 12:23:02 servicesext rpc.gssd[591]: xdr_rpc_gss_init_args: encod= e success (token 0xa04a1f0:586) Oct 26 12:23:02 servicesext rpc.gssd[591]: in authgss_validate() Oct 26 12:23:02 servicesext rpc.gssd[591]: xdr_rpc_gss_buf: decode succ= ess (0xa04c428:4) Oct 26 12:23:02 servicesext rpc.gssd[591]: xdr_rpc_gss_buf: decode succ= ess (0xa04b068:114) Oct 26 12:23:02 servicesext rpc.gssd[591]: xdr_rpc_gss_init_res decode = success (ctx 0xa04c428:4, maj 0, min 0, win 128, token 0xa04b068:114) Oct 26 12:23:02 servicesext rpc.gssd[591]: authgss_create_default: free= ing name 0xa04b370 Oct 26 12:23:02 servicesext rpc.gssd[591]: in authgss_get_private_data(= ) Oct 26 12:23:02 servicesext rpc.gssd[591]: DEBUG: serialize_krb5_ctx: l= ucid version! Oct 26 12:23:02 servicesext rpc.gssd[591]: prepare_krb5_rfc1964_buffer:= serializing keys with enctype 4 and length 8 Oct 26 12:23:02 servicesext rpc.gssd[591]: doing downcall Oct 26 12:23:02 servicesext rpc.gssd[591]: in authgss_free_private_data= () Oct 26 12:23:02 servicesext rpc.gssd[591]: in authgss_destroy() Oct 26 12:23:02 servicesext rpc.gssd[591]: in authgss_destroy_context() Oct 26 12:23:02 servicesext rpc.gssd[591]: authgss_destroy: freeing nam= e 0xa047b90 Oct 26 12:23:02 servicesext rpc.idmapd[587]: nfs4_name_to_uid: calling = nsswitch->name_to_uid Oct 26 12:23:02 servicesext rpc.idmapd[587]: nss_getpwnam: name 'root@d= esmier.org' domain 'desmier.org': resulting localname 'root' Oct 26 12:23:02 servicesext rpc.idmapd[587]: nfs4_name_to_uid: nsswitch= ->name_to_uid returned 0 Oct 26 12:23:02 servicesext rpc.idmapd[587]: nfs4_name_to_uid: final re= turn value is 0 Oct 26 12:23:02 servicesext rpc.idmapd[587]: Client 2: (user) name "roo= t@desmier.org" -> id "0" Oct 26 12:23:02 servicesext rpc.idmapd[587]: nfs4_name_to_gid: calling = nsswitch->name_to_gid Oct 26 12:23:02 servicesext rpc.idmapd[587]: nfs4_name_to_gid: nsswitch= ->name_to_gid returned 0 Oct 26 12:23:02 servicesext rpc.idmapd[587]: nfs4_name_to_gid: final re= turn value is 0 Oct 26 12:23:02 servicesext rpc.idmapd[587]: Client 2: (group) name "ro= ot-1jBem2fKKG1AfugRpC6u6w@public.gmane.org" -> id "0" Oct 26 12:23:02 servicesext rpc.idmapd[587]: New client: 4 Oct 26 12:23:02 servicesext rpc.gssd[591]: destroying client /var/lib/n= fs/rpc_pipefs/nfs/clnt3 Oct 26 12:23:02 servicesext rpc.idmapd[587]: Stale client: 3 Oct 26 12:23:02 servicesext rpc.idmapd[587]: #011-> closed /var/lib/nfs= /rpc_pipefs/nfs/clnt3/idmap - Nashome syslog :=20 Oct 26 12:23:00 nashome rpc.svcgssd[2876]: leaving poll Oct 26 12:23:00 nashome rpc.svcgssd[2876]: handling null request Oct 26 12:23:00 nashome rpc.svcgssd[2876]: sname =3D nfs/servicesext.de= smier.org-HBhUyB7S6INF7rqys1CUDA@public.gmane.org Oct 26 12:23:00 nashome rpc.svcgssd[2876]: libnfsidmap: using domain: d= esmier.org Oct 26 12:23:00 nashome rpc.svcgssd[2876]: libnfsidmap: processing 'Met= hod' list Oct 26 12:23:00 nashome rpc.svcgssd[2876]: libnfsidmap: loaded plugin /= usr/lib/libnfsidmap/nsswitch.so for method nsswitch Oct 26 12:23:00 nashome rpc.svcgssd[2876]: DEBUG: serialize_krb5_ctx: l= ucid version! Oct 26 12:23:00 nashome rpc.svcgssd[2876]: prepare_krb5_rfc1964_buffer:= serializing keys with enctype 4 and length 8 Oct 26 12:23:00 nashome rpc.svcgssd[2876]: doing downcall Oct 26 12:23:00 nashome rpc.svcgssd[2876]: mech: krb5, hndl len: 4, ctx= len 85, timeout: 1288123449 (34869 from now), clnt: nfs-fruN6kYK4IH0mRrQNGSQYw@public.gmane.org= smier.org, uid: -1, gid: -1, num aux grps: 0: Oct 26 12:23:00 nashome rpc.svcgssd[2876]: sending null reply Oct 26 12:23:00 nashome rpc.svcgssd[2876]: writing message: \x \x608202= 4606092a864886f71201020201006e82023530820231a003020105a10302010ea207030= 50020000000a38201596182015530820151a003020105a10d1b0b4445534d4945522e4f= 5247a2253023a003020103a11c301a1b036e66731b136e6173686f6d652e6465736d696= 5722e6f7267a38201123082010ea003020112a103020107a28201000481fdd265dab6ac= 3f0baf6338d64153d32b4873c93c166b66eff6cb7b48e85f13a24d21fc7d0fb94e76cc1= 4df4d4d2291588b7759fb497d2c23c622f9dd1da834a97c0a2027e075444a846f63747d= 375b6db9ad5aae106e639703653bec4e7a8e06f6dcbd1d3c03305fb3b01d84024697e2c= fa34277d15ec1b96c164d344ca00444335ccefdcdf275ab6cb6767adf1d2706b9f0ce32= d6bde3e9729e807dd4471531b1f96a31dda0be6938782724b7e72983c7ae796abeac1dd= ec8fab06e486bbab2c5c5fe789b93fa3eabc994142920ba4b725c2266bd615c08f4d603= 748fb568ff7f921105a379425fcff276db52560e53198faf29ba55345951d89b322318a= 481be3081bba003020101a281b30481b0e668f43c88a2cfa3307744065a47b7700539eb= 9e9d10599ec1a2256f299d4aea4a8ebcf2d48d42bcd3a5625e3b5d567d14b22b5cb f8a39c1e222ac02681248525b0053ea2ea29f1fb43d9d1c7cac3c6597569b402b0c902= 450fba2395b29dd99d036fe8c4d124fbcc955e465af1f9c65ba111e6c5116e2806e12b0= 6a8ba507ec84c18a2f8a3622da83a100f91021338cfd2e4f7534f91884af1995d76363d= 2527e020b88527015ac8a8667324895778d 1288088640 0 0 \x01000000 \x6070060= 92a864886f71201020202006f61305fa003020105a10302010fa2533051a003020101a2= 4a04481c649c866a6c25d3dd3cd5624ccdf9dd26b53134870418ef7137c6da82a5d4da9= 0573edec195a852395593fd4fda7179cb0e40d3481544807d982e25aadc80b3e42e2573= 4dcefeb8=20 Oct 26 12:23:00 nashome rpc.svcgssd[2876]: finished handling null reque= st Oct 26 12:23:00 nashome rpc.svcgssd[2876]: entering poll Oct 26 12:23:00 nashome rpc.idmapd[2821]: nfsdcb: authbuf=3Dgss/krb5 au= thtype=3Duser Oct 26 12:23:00 nashome rpc.idmapd[2821]: Server: (user) id "0" -> nam= e "root-1jBem2fKKG1AfugRpC6u6w@public.gmane.org" Oct 26 12:23:00 nashome rpc.idmapd[2821]: nfsdcb: authbuf=3Dgss/krb5 au= thtype=3Dgroup Oct 26 12:23:00 nashome rpc.idmapd[2821]: Server: (group) id "0" -> na= me "root-1jBem2fKKG1AfugRpC6u6w@public.gmane.org" - servicesint Kerberos KDC logs : nothing new, credentials are in cache. Did someone already encountered that kind of problem? I've tried a lot = tutorials in internet but each time when I use a security flavor like s= ys with an other share with gss/krb5, mount command never ends when mou= nting gss/krb5 share. Following /etc/exports doesn't work unless I remo= ve the first line. Once the first line removed, I can mount using krb5[= i][p] security flavor. /export *(rw,fsid=3D0,insecure,no_subtree_check) /export gss/krb5(rw,fsid=3D0,insecure,no_subtree_check) /export gss/krb5i(rw,fsid=3D0,insecure,no_subtree_check) /export gss/krb5p(rw,fsid=3D0,insecure,no_subtree_check) Thanks for any help, advices, best practices, tips... Arnaud -- To unsubscribe from this list: send the line "unsubscribe linux-nfs" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html ^ permalink raw reply [flat|nested] 3+ messages in thread
* Re: Problems using sec=krb5 with also sec=sys in any share 2010-10-28 11:49 ` arnaud.desmier @ 2010-11-16 19:15 ` J. Bruce Fields 0 siblings, 0 replies; 3+ messages in thread From: J. Bruce Fields @ 2010-11-16 19:15 UTC (permalink / raw) To: arnaud.desmier; +Cc: linux-nfs On Thu, Oct 28, 2010 at 01:49:34PM +0200, arnaud.desmier@free.fr wrote: > No idea about this problem? no one encountered the same problem? > > Maybe there is an other mailing list for this kind of problem? On a quick skim nothing jumps out at me. If I were you my next step would be to run wireshark and see if you can figure out what happens on the wire in the case where there's a hang. What are the client and server kernel versions? > > Thanks, > > Arnaud > > ----- Mail Original ----- > De: "arnaud desmier" <arnaud.desmier@free.fr> > À: linux-nfs@vger.kernel.org > Envoyé: Mardi 26 Octobre 2010 14h08:10 GMT +01:00 Amsterdam / Berlin / Berne / Rome / Stockholm / Vienne > Objet: Problems using sec=krb5 with also sec=sys in any share > > Hi all, > > I'm trying to share some folders like /home and /var/mail with differents security flavors between some machines in a virtual network using VirtualBox. My virtual network is compunded of : > - my NFS server, also called nashome, IP address : 192.168.10.5. It's a Debian Squeeze Virtual Machine, using nfs-utils 1.2.2 > - my email server, also called servicesext (external services), IP address : 10.1.2.10. It's a Debian Squeeze Virtual Machine, using nfs-utils 1.2.2 > - my kerberos (MIT) server, also called serviceint (internal services), IP address : 192.168.10.4. It's a Debian Squeeze Virtual Machine > - my user computer, also called posteA, IP address : 192.168.10.50. It's an Ubuntu 10.10 > > NFS shared folders constraints are following : > - /home must be accessed using kerberos identification, I have to mount it on servicesext and posteA > - /var/mail is filled by exim4 so I can't use kerberos authentication, only sys flavor, I have to mount it on servicesext only > > /export/home and /export/mail are bind mount : > mount --bind /var/mail/ /export/mail/ > mount --bind /home /export/home/ > > All Squeeze machines have been updated at the same time and tests have reproduced using nfs-utils 1.2.2 with and without debian patches, and also with nfs-utils 1.2.3. Each time the same result. > > 1. Each time, when a share folder is set with sec=krb5 as security flavor, client is blocked and mount command never ends. For example (/etc/exports) : > /export -fsid=0,insecure,no_subtree_check 10.1.2.10(sec=sys:krb5) 192.168.10.50(sec=krb5) > /export/home -sec=krb5,rw,nohide,insecure,no_subtree_check 192.168.10.50 10.1.2.10 > /export/mail -sec=sys,rw,nohide,insecure,no_subtree_check 10.1.2.10 I can't see off hand why that shouldn't work.... > - Using my servicesext (10.1.2.10) machine, I can mount nashome:/mail : > # umount /mnt/nfs4; mount -t nfs4 nashome:/mail /mnt/nfs4 -vvvv > - but when I try to mount nashome:/home, mount command never ends (see logs below) > # umount /mnt/nfs4; mount -t nfs4 -o sec=krb5 nashome:/home /mnt/nfs4 -vvvv > > > 2. Instead of using sec=krb5, I will use old expression gss/krb5 : the following does not work > /export -fsid=0,insecure,no_subtree_check 10.1.2.10(sec=sys:krb5) 192.168.10.50(sec=krb5) gss/krb5 > /export/home -sec=krb5,rw,nohide,insecure,no_subtree_check 192.168.10.50 10.1.2.10 gss/krb5 > /export/mail -sec=sys,rw,nohide,insecure,no_subtree_check 10.1.2.10 > > > 3. And an amazing thing, if I remove all authentications except gss/krb5 I can mount nashome:/home (see logs below). Mounting on posteA works only if I remove it's IP address 192.168.10.50 from second line. Yeah, exports that vary security flavor requirements based on ip address were never supported with the old syntax. --b. > /export -fsid=0,insecure,no_subtree_check gss/krb5 > /export/home -rw,nohide,insecure,no_subtree_check 192.168.10.50 gss/krb5 > #/export/mail -sec=sys,rw,nohide,insecure,no_subtree_check 10.1.2.10 > > > Following are logs files for mount and syslog on servicesext, nashome syslog, and servicesint Kerberos KDC logs for step 1 when mounting nashome:/home > > - mount logs : > 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: "nashome:/home" > mount: node: "/mnt/nfs4" > mount: types: "nfs4" > mount: opts: "sec=krb5" > mount: external mount: argv[0] = "/sbin/mount.nfs4" > mount: external mount: argv[1] = "nashome:/home" > mount: external mount: argv[2] = "/mnt/nfs4" > 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 Tue Oct 26 12:06:40 2010 > mount.nfs4: trying text-based options 'sec=krb5,addr=192.168.10.5,clientaddr=10.1.2.10' > > > - Servicesext syslog : > Oct 26 12:04:40 servicesext rpc.idmapd[587]: New client: 0 > Oct 26 12:04:40 servicesext rpc.idmapd[587]: Opened /var/lib/nfs/rpc_pipefs/nfs/clnt0/idmap > Oct 26 12:04:40 servicesext rpc.idmapd[587]: New client: 1 > Oct 26 12:04:40 servicesext rpc.gssd[591]: handling gssd upcall (/var/lib/nfs/rpc_pipefs/nfs/clnt0) > Oct 26 12:04:40 servicesext rpc.gssd[591]: handle_gssd_upcall: 'mech=krb5 uid=0 ' > Oct 26 12:04:40 servicesext rpc.gssd[591]: handling krb5 upcall (/var/lib/nfs/rpc_pipefs/nfs/clnt0) > Oct 26 12:04:40 servicesext rpc.gssd[591]: process_krb5_upcall: service is '<null>' > Oct 26 12:04:40 servicesext rpc.gssd[591]: Full hostname for 'nashome.desmier.org' is 'nashome.desmier.org' > Oct 26 12:04:40 servicesext rpc.gssd[591]: Full hostname for 'servicesext.desmier.org' is 'servicesext.desmier.org' > Oct 26 12:04:40 servicesext rpc.gssd[591]: Key table entry not found while getting keytab entry for 'root/servicesext.desmier.org@DESMIER.ORG' > Oct 26 12:04:40 servicesext rpc.gssd[591]: Success getting keytab entry for 'nfs/servicesext.desmier.org@DESMIER.ORG' > Oct 26 12:04:40 servicesext rpc.gssd[591]: Successfully obtained machine credentials for principal 'nfs/servicesext.desmier.org@DESMIER.ORG' stored in ccache 'FILE:/tmp/krb5cc_machine_DESMIER.ORG' > Oct 26 12:04:40 servicesext rpc.gssd[591]: INFO: Credentials in CC 'FILE:/tmp/krb5cc_machine_DESMIER.ORG' are good until 1288123449 > Oct 26 12:04:40 servicesext rpc.gssd[591]: using FILE:/tmp/krb5cc_machine_DESMIER.ORG as credentials cache for machine creds > Oct 26 12:04:40 servicesext rpc.gssd[591]: using environment variable to select krb5 ccache FILE:/tmp/krb5cc_machine_DESMIER.ORG > Oct 26 12:04:40 servicesext rpc.gssd[591]: creating context using fsuid 0 (save_uid 0) > Oct 26 12:04:40 servicesext rpc.gssd[591]: creating tcp client for server nashome.desmier.org > Oct 26 12:04:40 servicesext rpc.gssd[591]: DEBUG: port already set to 2049 > Oct 26 12:04:40 servicesext rpc.gssd[591]: creating context with server nfs@nashome.desmier.org > Oct 26 12:04:40 servicesext rpc.gssd[591]: in authgss_create_default() > Oct 26 12:04:40 servicesext rpc.gssd[591]: in authgss_create() > Oct 26 12:04:40 servicesext rpc.gssd[591]: authgss_create: name is 0xa047908 > Oct 26 12:04:40 servicesext rpc.gssd[591]: authgss_create: gd->name is 0xa047e38 > Oct 26 12:04:40 servicesext rpc.gssd[591]: in authgss_refresh() > Oct 26 12:04:40 servicesext rpc.gssd[591]: struct rpc_gss_sec: > Oct 26 12:04:40 servicesext rpc.gssd[591]: mechanism_OID: { 1 2 134 72 134 247 18 1 2 2 } > Oct 26 12:04:40 servicesext rpc.gssd[591]: qop: 0 > Oct 26 12:04:40 servicesext rpc.gssd[591]: service: 1 > Oct 26 12:04:40 servicesext rpc.gssd[591]: cred: 0xa047c10 > Oct 26 12:04:40 servicesext rpc.gssd[591]: req_flags: 00000002 > Oct 26 12:04:40 servicesext rpc.gssd[591]: in authgss_marshal() > Oct 26 12:04:40 servicesext rpc.gssd[591]: xdr_rpc_gss_buf: encode success ((nil):0) > Oct 26 12:04:40 servicesext rpc.gssd[591]: xdr_rpc_gss_cred: encode success (v 1, proc 1, seq 0, svc 1, ctx (nil):0) > Oct 26 12:04:40 servicesext rpc.gssd[591]: xdr_rpc_gss_buf: encode success (0xa04b410:586) > Oct 26 12:04:40 servicesext rpc.gssd[591]: xdr_rpc_gss_init_args: encode success (token 0xa04b410:586) > Oct 26 12:04:40 servicesext rpc.gssd[591]: in authgss_validate() > Oct 26 12:04:40 servicesext rpc.gssd[591]: xdr_rpc_gss_buf: decode success (0xa047440:4) > Oct 26 12:04:40 servicesext rpc.gssd[591]: xdr_rpc_gss_buf: decode success (0xa04b660:114) > Oct 26 12:04:40 servicesext rpc.gssd[591]: xdr_rpc_gss_init_res decode success (ctx 0xa047440:4, maj 0, min 0, win 128, token 0xa04b660:114) > Oct 26 12:04:40 servicesext rpc.gssd[591]: authgss_create_default: freeing name 0xa047908 > Oct 26 12:04:40 servicesext rpc.gssd[591]: in authgss_get_private_data() > Oct 26 12:04:40 servicesext rpc.gssd[591]: DEBUG: serialize_krb5_ctx: lucid version! > Oct 26 12:04:40 servicesext rpc.gssd[591]: prepare_krb5_rfc1964_buffer: serializing keys with enctype 4 and length 8 > Oct 26 12:04:40 servicesext rpc.gssd[591]: doing downcall > Oct 26 12:04:40 servicesext rpc.gssd[591]: in authgss_free_private_data() > Oct 26 12:04:40 servicesext rpc.gssd[591]: in authgss_destroy() > Oct 26 12:04:40 servicesext rpc.gssd[591]: in authgss_destroy_context() > Oct 26 12:04:40 servicesext rpc.gssd[591]: authgss_destroy: freeing name 0xa047e38 > Oct 26 12:07:40 servicesext kernel: [ 231.993067] nfs: server nashome not responding, still trying > > - When I kill mount with Ctrl+C : > Oct 26 12:22:13 servicesext rpc.idmapd[587]: Stale client: 1 > Oct 26 12:22:13 servicesext rpc.idmapd[587]: #011-> closed /var/lib/nfs/rpc_pipefs/nfs/clnt1/idmap > Oct 26 12:22:13 servicesext rpc.idmapd[587]: Stale client: 0 > Oct 26 12:22:13 servicesext rpc.idmapd[587]: #011-> closed /var/lib/nfs/rpc_pipefs/nfs/clnt0/idmap > Oct 26 12:22:13 servicesext rpc.gssd[591]: destroying client /var/lib/nfs/rpc_pipefs/nfs/clnt1 > Oct 26 12:22:13 servicesext rpc.gssd[591]: destroying client /var/lib/nfs/rpc_pipefs/nfs/clnt0 > > > - Nashome syslog : > Oct 26 12:04:09 nashome rpc.svcgssd[2775]: leaving poll > Oct 26 12:04:09 nashome rpc.svcgssd[2775]: handling null request > Oct 26 12:04:09 nashome rpc.svcgssd[2775]: sname = nfs/servicesext.desmier.org@DESMIER.ORG > Oct 26 12:04:09 nashome rpc.svcgssd[2775]: DEBUG: serialize_krb5_ctx: lucid version! > Oct 26 12:04:09 nashome rpc.svcgssd[2775]: prepare_krb5_rfc1964_buffer: serializing keys with enctype 4 and length 8 > Oct 26 12:04:09 nashome rpc.svcgssd[2775]: doing downcall > Oct 26 12:04:09 nashome rpc.svcgssd[2775]: mech: krb5, hndl len: 4, ctx len 85, timeout: 1288123449 (36000 from now), clnt: nfs@servicesext.desmier.org, uid: -1, gid: -1, num aux grps: 0: > Oct 26 12:04:09 nashome rpc.svcgssd[2775]: sending null reply > Oct 26 12:04:09 nashome rpc.svcgssd[2775]: writing message: \x \x6082024606092a864886f71201020201006e82023530820231a003020105a10302010ea20703050020000000a38201596182015530820151a003020105a10d1b0b4445534d4945522e4f5247a2253023a003020103a11c301a1b036e66731b136e6173686f6d652e6465736d6965722e6f7267a38201123082010ea003020112a103020107a28201000481fdd265dab6ac3f0baf6338d64153d32b4873c93c166b66eff6cb7b48e85f13a24d21fc7d0fb94e76cc14df4d4d2291588b7759fb497d2c23c622f9dd1da834a97c0a2027e075444a846f63747d375b6db9ad5aae106e639703653bec4e7a8e06f6dcbd1d3c03305fb3b01d84024697e2cfa34277d15ec1b96c164d344ca00444335ccefdcdf275ab6cb6767adf1d2706b9f0ce32d6bde3e9729e807dd4471531b1f96a31dda0be6938782724b7e72983c7ae796abeac1ddec8fab06e486bbab2c5c5fe789b93fa3eabc994142920ba4b725c2266bd615c08f4d603748fb568ff7f921105a379425fcff276db52560e53198faf29ba55345951d89b322318a481be3081bba003020101a281b30481b0be97d17110d6ca7d64716a301d5b741256068040fa844a607613cb8fc1235774c3a4fbe5669fdc8edcf92af25a6651cdd8cb11! b4f > ccf06affbe76e4d9905d8cfa1c6202990b3471895f37ff1ba5d5caf9d7980c2b0a7fffe67e0f9c2b7929d10488034727b013e725abae91fce125d1fae14f0959e714442e459f0868db3af26b395386f854fcb450d5889321250a75a0f142dcfb721e244aa2233e269d65e9f1f20a1350f691765210c2eb7ddfcab78 1288087509 0 0 \x02000000 \x607006092a864886f71201020202006f61305fa003020105a10302010fa2533051a003020101a24a0448cdd3980ca17e39234e4b5f8d0ed3295cf4716a92830ae3d61fa5716d69d41cf6d5d6e676e0a35ef1d02bd1014fb6191846add36ae5b15b2e820f23f4ccaceb4ec63431bb0df9dcbe > Oct 26 12:04:09 nashome rpc.svcgssd[2775]: finished handling null request > Oct 26 12:04:09 nashome rpc.svcgssd[2775]: entering poll > > > - servicesint Kerberos KDC logs : > Oct 26 12:04:09 servicesint krb5kdc[1000](info): AS_REQ (7 etypes {18 17 16 23 1 3 2}) 10.1.2.10: NEEDED_PREAUTH: nfs/servicesext.desmier.org@DESMIER.ORG for krbtgt/DESMIER.ORG@DESMIER.ORG, Additional pre-authentication required > Oct 26 12:04:09 servicesint krb5kdc[1000](info): AS_REQ (7 etypes {18 17 16 23 1 3 2}) 10.1.2.10: ISSUE: authtime 1288087449, etypes {rep=18 tkt=18 ses=18}, nfs/servicesext.desmier.org@DESMIER.ORG for krbtgt/DESMIER.ORG@DESMIER.ORG > Oct 26 12:04:09 servicesint krb5kdc[1000](info): TGS_REQ (7 etypes {18 17 16 23 1 3 2}) 10.1.2.10: ISSUE: authtime 1288087449, etypes {rep=18 tkt=18 ses=18}, nfs/servicesext.desmier.org@DESMIER.ORG for nfs/nashome.desmier.org@DESMIER.ORG > Oct 26 12:04:09 servicesint krb5kdc[1000](info): TGS_REQ (3 etypes {1 3 2}) 10.1.2.10: ISSUE: authtime 1288087449, etypes {rep=18 tkt=18 ses=1}, nfs/servicesext.desmier.org@DESMIER.ORG for nfs/nashome.desmier.org@DESMIER.ORG > > > Following are logs files for mount and syslog on servicesext, nashome syslog, and servicesint Kerberos KDC logs for step 3 when mounting nashome:/home > > - Servicesext mount logs : > 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: "nashome:/home" > mount: node: "/mnt/nfs4" > mount: types: "nfs4" > mount: opts: "sec=krb5" > mount: external mount: argv[0] = "/sbin/mount.nfs4" > mount: external mount: argv[1] = "nashome:/home" > mount: external mount: argv[2] = "/mnt/nfs4" > 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 Tue Oct 26 12:25:02 2010 > mount.nfs4: trying text-based options 'sec=krb5,addr=192.168.10.5,clientaddr=10.1.2.10' > nashome:/home on /mnt/nfs4 type nfs4 (rw,sec=krb5) > > - Servicesext syslog : > ct 26 12:23:02 servicesext rpc.idmapd[587]: New client: 2 > Oct 26 12:23:02 servicesext rpc.idmapd[587]: Opened /var/lib/nfs/rpc_pipefs/nfs/clnt2/idmap > Oct 26 12:23:02 servicesext rpc.gssd[591]: handling gssd upcall (/var/lib/nfs/rpc_pipefs/nfs/clnt2) > Oct 26 12:23:02 servicesext rpc.gssd[591]: handle_gssd_upcall: 'mech=krb5 uid=0 ' > Oct 26 12:23:02 servicesext rpc.gssd[591]: handling krb5 upcall (/var/lib/nfs/rpc_pipefs/nfs/clnt2) > Oct 26 12:23:02 servicesext rpc.gssd[591]: process_krb5_upcall: service is '<null>' > Oct 26 12:23:02 servicesext rpc.idmapd[587]: New client: 3 > Oct 26 12:23:02 servicesext rpc.gssd[591]: Full hostname for 'nashome.desmier.org' is 'nashome.desmier.org' > Oct 26 12:23:02 servicesext rpc.gssd[591]: Full hostname for 'servicesext.desmier.org' is 'servicesext.desmier.org' > Oct 26 12:23:02 servicesext rpc.gssd[591]: Key table entry not found while getting keytab entry for 'root/servicesext.desmier.org@DESMIER.ORG' > Oct 26 12:23:02 servicesext rpc.gssd[591]: Success getting keytab entry for 'nfs/servicesext.desmier.org@DESMIER.ORG' > Oct 26 12:23:02 servicesext rpc.gssd[591]: INFO: Credentials in CC 'FILE:/tmp/krb5cc_machine_DESMIER.ORG' are good until 1288123449 > Oct 26 12:23:02 servicesext rpc.gssd[591]: INFO: Credentials in CC 'FILE:/tmp/krb5cc_machine_DESMIER.ORG' are good until 1288123449 > Oct 26 12:23:02 servicesext rpc.gssd[591]: using FILE:/tmp/krb5cc_machine_DESMIER.ORG as credentials cache for machine creds > Oct 26 12:23:02 servicesext rpc.gssd[591]: using environment variable to select krb5 ccache FILE:/tmp/krb5cc_machine_DESMIER.ORG > Oct 26 12:23:02 servicesext rpc.gssd[591]: creating context using fsuid 0 (save_uid 0) > Oct 26 12:23:02 servicesext rpc.gssd[591]: creating tcp client for server nashome.desmier.org > Oct 26 12:23:02 servicesext rpc.gssd[591]: DEBUG: port already set to 2049 > Oct 26 12:23:02 servicesext rpc.gssd[591]: creating context with server nfs@nashome.desmier.org > Oct 26 12:23:02 servicesext rpc.gssd[591]: in authgss_create_default() > Oct 26 12:23:02 servicesext rpc.gssd[591]: in authgss_create() > Oct 26 12:23:02 servicesext rpc.gssd[591]: authgss_create: name is 0xa04b370 > Oct 26 12:23:02 servicesext rpc.gssd[591]: authgss_create: gd->name is 0xa047b90 > Oct 26 12:23:02 servicesext rpc.gssd[591]: in authgss_refresh() > Oct 26 12:23:02 servicesext rpc.gssd[591]: struct rpc_gss_sec: > Oct 26 12:23:02 servicesext rpc.gssd[591]: mechanism_OID: { 1 2 134 72 134 247 18 1 2 2 } > Oct 26 12:23:02 servicesext rpc.gssd[591]: qop: 0 > Oct 26 12:23:02 servicesext rpc.gssd[591]: service: 1 > Oct 26 12:23:02 servicesext rpc.gssd[591]: cred: 0xa04b390 > Oct 26 12:23:02 servicesext rpc.gssd[591]: req_flags: 00000002 > Oct 26 12:23:02 servicesext rpc.gssd[591]: in authgss_marshal() > Oct 26 12:23:02 servicesext rpc.gssd[591]: xdr_rpc_gss_buf: encode success ((nil):0) > Oct 26 12:23:02 servicesext rpc.gssd[591]: xdr_rpc_gss_cred: encode success (v 1, proc 1, seq 0, svc 1, ctx (nil):0) > Oct 26 12:23:02 servicesext rpc.gssd[591]: xdr_rpc_gss_buf: encode success (0xa04a1f0:586) > Oct 26 12:23:02 servicesext rpc.gssd[591]: xdr_rpc_gss_init_args: encode success (token 0xa04a1f0:586) > Oct 26 12:23:02 servicesext rpc.gssd[591]: in authgss_validate() > Oct 26 12:23:02 servicesext rpc.gssd[591]: xdr_rpc_gss_buf: decode success (0xa04c428:4) > Oct 26 12:23:02 servicesext rpc.gssd[591]: xdr_rpc_gss_buf: decode success (0xa04b068:114) > Oct 26 12:23:02 servicesext rpc.gssd[591]: xdr_rpc_gss_init_res decode success (ctx 0xa04c428:4, maj 0, min 0, win 128, token 0xa04b068:114) > Oct 26 12:23:02 servicesext rpc.gssd[591]: authgss_create_default: freeing name 0xa04b370 > Oct 26 12:23:02 servicesext rpc.gssd[591]: in authgss_get_private_data() > Oct 26 12:23:02 servicesext rpc.gssd[591]: DEBUG: serialize_krb5_ctx: lucid version! > Oct 26 12:23:02 servicesext rpc.gssd[591]: prepare_krb5_rfc1964_buffer: serializing keys with enctype 4 and length 8 > Oct 26 12:23:02 servicesext rpc.gssd[591]: doing downcall > Oct 26 12:23:02 servicesext rpc.gssd[591]: in authgss_free_private_data() > Oct 26 12:23:02 servicesext rpc.gssd[591]: in authgss_destroy() > Oct 26 12:23:02 servicesext rpc.gssd[591]: in authgss_destroy_context() > Oct 26 12:23:02 servicesext rpc.gssd[591]: authgss_destroy: freeing name 0xa047b90 > Oct 26 12:23:02 servicesext rpc.idmapd[587]: nfs4_name_to_uid: calling nsswitch->name_to_uid > Oct 26 12:23:02 servicesext rpc.idmapd[587]: nss_getpwnam: name 'root@desmier.org' domain 'desmier.org': resulting localname 'root' > Oct 26 12:23:02 servicesext rpc.idmapd[587]: nfs4_name_to_uid: nsswitch->name_to_uid returned 0 > Oct 26 12:23:02 servicesext rpc.idmapd[587]: nfs4_name_to_uid: final return value is 0 > Oct 26 12:23:02 servicesext rpc.idmapd[587]: Client 2: (user) name "root@desmier.org" -> id "0" > Oct 26 12:23:02 servicesext rpc.idmapd[587]: nfs4_name_to_gid: calling nsswitch->name_to_gid > Oct 26 12:23:02 servicesext rpc.idmapd[587]: nfs4_name_to_gid: nsswitch->name_to_gid returned 0 > Oct 26 12:23:02 servicesext rpc.idmapd[587]: nfs4_name_to_gid: final return value is 0 > Oct 26 12:23:02 servicesext rpc.idmapd[587]: Client 2: (group) name "root@desmier.org" -> id "0" > Oct 26 12:23:02 servicesext rpc.idmapd[587]: New client: 4 > Oct 26 12:23:02 servicesext rpc.gssd[591]: destroying client /var/lib/nfs/rpc_pipefs/nfs/clnt3 > Oct 26 12:23:02 servicesext rpc.idmapd[587]: Stale client: 3 > Oct 26 12:23:02 servicesext rpc.idmapd[587]: #011-> closed /var/lib/nfs/rpc_pipefs/nfs/clnt3/idmap > > > > - Nashome syslog : > Oct 26 12:23:00 nashome rpc.svcgssd[2876]: leaving poll > Oct 26 12:23:00 nashome rpc.svcgssd[2876]: handling null request > Oct 26 12:23:00 nashome rpc.svcgssd[2876]: sname = nfs/servicesext.desmier.org@DESMIER.ORG > Oct 26 12:23:00 nashome rpc.svcgssd[2876]: libnfsidmap: using domain: desmier.org > Oct 26 12:23:00 nashome rpc.svcgssd[2876]: libnfsidmap: processing 'Method' list > Oct 26 12:23:00 nashome rpc.svcgssd[2876]: libnfsidmap: loaded plugin /usr/lib/libnfsidmap/nsswitch.so for method nsswitch > Oct 26 12:23:00 nashome rpc.svcgssd[2876]: DEBUG: serialize_krb5_ctx: lucid version! > Oct 26 12:23:00 nashome rpc.svcgssd[2876]: prepare_krb5_rfc1964_buffer: serializing keys with enctype 4 and length 8 > Oct 26 12:23:00 nashome rpc.svcgssd[2876]: doing downcall > Oct 26 12:23:00 nashome rpc.svcgssd[2876]: mech: krb5, hndl len: 4, ctx len 85, timeout: 1288123449 (34869 from now), clnt: nfs@servicesext.desmier.org, uid: -1, gid: -1, num aux grps: 0: > Oct 26 12:23:00 nashome rpc.svcgssd[2876]: sending null reply > Oct 26 12:23:00 nashome rpc.svcgssd[2876]: writing message: \x \x6082024606092a864886f71201020201006e82023530820231a003020105a10302010ea20703050020000000a38201596182015530820151a003020105a10d1b0b4445534d4945522e4f5247a2253023a003020103a11c301a1b036e66731b136e6173686f6d652e6465736d6965722e6f7267a38201123082010ea003020112a103020107a28201000481fdd265dab6ac3f0baf6338d64153d32b4873c93c166b66eff6cb7b48e85f13a24d21fc7d0fb94e76cc14df4d4d2291588b7759fb497d2c23c622f9dd1da834a97c0a2027e075444a846f63747d375b6db9ad5aae106e639703653bec4e7a8e06f6dcbd1d3c03305fb3b01d84024697e2cfa34277d15ec1b96c164d344ca00444335ccefdcdf275ab6cb6767adf1d2706b9f0ce32d6bde3e9729e807dd4471531b1f96a31dda0be6938782724b7e72983c7ae796abeac1ddec8fab06e486bbab2c5c5fe789b93fa3eabc994142920ba4b725c2266bd615c08f4d603748fb568ff7f921105a379425fcff276db52560e53198faf29ba55345951d89b322318a481be3081bba003020101a281b30481b0e668f43c88a2cfa3307744065a47b7700539eb9e9d10599ec1a2256f299d4aea4a8ebcf2d48d42bcd3a5625e3b5d567d14b22b! 5cb > f8a39c1e222ac02681248525b0053ea2ea29f1fb43d9d1c7cac3c6597569b402b0c902450fba2395b29dd99d036fe8c4d124fbcc955e465af1f9c65ba111e6c5116e2806e12b06a8ba507ec84c18a2f8a3622da83a100f91021338cfd2e4f7534f91884af1995d76363d2527e020b88527015ac8a8667324895778d 1288088640 0 0 \x01000000 \x607006092a864886f71201020202006f61305fa003020105a10302010fa2533051a003020101a24a04481c649c866a6c25d3dd3cd5624ccdf9dd26b53134870418ef7137c6da82a5d4da90573edec195a852395593fd4fda7179cb0e40d3481544807d982e25aadc80b3e42e25734dcefeb8 > Oct 26 12:23:00 nashome rpc.svcgssd[2876]: finished handling null request > Oct 26 12:23:00 nashome rpc.svcgssd[2876]: entering poll > Oct 26 12:23:00 nashome rpc.idmapd[2821]: nfsdcb: authbuf=gss/krb5 authtype=user > Oct 26 12:23:00 nashome rpc.idmapd[2821]: Server: (user) id "0" -> name "root@desmier.org" > Oct 26 12:23:00 nashome rpc.idmapd[2821]: nfsdcb: authbuf=gss/krb5 authtype=group > Oct 26 12:23:00 nashome rpc.idmapd[2821]: Server: (group) id "0" -> name "root@desmier.org" > > - servicesint Kerberos KDC logs : > nothing new, credentials are in cache. > > > Did someone already encountered that kind of problem? I've tried a lot tutorials in internet but each time when I use a security flavor like sys with an other share with gss/krb5, mount command never ends when mounting gss/krb5 share. Following /etc/exports doesn't work unless I remove the first line. Once the first line removed, I can mount using krb5[i][p] security flavor. > /export *(rw,fsid=0,insecure,no_subtree_check) > /export gss/krb5(rw,fsid=0,insecure,no_subtree_check) > /export gss/krb5i(rw,fsid=0,insecure,no_subtree_check) > /export gss/krb5p(rw,fsid=0,insecure,no_subtree_check) > > > Thanks for any help, advices, best practices, tips... > > Arnaud > -- > To unsubscribe from this list: send the line "unsubscribe linux-nfs" in > the body of a message to majordomo@vger.kernel.org > More majordomo info at http://vger.kernel.org/majordomo-info.html > -- > To unsubscribe from this list: send the line "unsubscribe linux-nfs" in > the body of a message to majordomo@vger.kernel.org > More majordomo info at http://vger.kernel.org/majordomo-info.html ^ permalink raw reply [flat|nested] 3+ messages in thread
end of thread, other threads:[~2010-11-16 19:15 UTC | newest]
Thread overview: 3+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
[not found] <1814327585.428221288089705648.JavaMail.root@spooler8-g27.priv.proxad.net>
2010-10-26 12:08 ` Problems using sec=krb5 with also sec=sys in any share arnaud.desmier
[not found] <1215084548.814871288266525238.JavaMail.root@spooler8-g27.priv.proxad.net>
[not found] ` <1215084548.814871288266525238.JavaMail.root-x5ewXQG5twBsFmKuirFwRhh1pbbyJDp15NbjCUgZEJk@public.gmane.org>
2010-10-28 11:49 ` arnaud.desmier
2010-11-16 19:15 ` J. Bruce Fields
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).