Your message dated Sat, 14 Sep 2024 09:59:42 +0200 (CEST)
with message-id <20240914075942.3e721be2...@eldamar.lan>
and subject line Closing this bug (BTS maintenance for src:linux bugs)
has caused the Debian Bug report #753732,
regarding NFS sec=krb5 does not work with cross-realm
to be marked as done.
This means that you claim that the problem has been dealt with.
If this is not the case it is now your responsibility to reopen the
Bug report if necessary, and/or fix the problem forthwith.
(NB: If you are a system administrator and have no idea what this
message is talking about, this may indicate a serious mail system
misconfiguration somewhere. Please contact ow...@bugs.debian.org
immediately.)
--
753732: https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=753732
Debian Bug Tracking System
Contact ow...@bugs.debian.org with problems
--- Begin Message ---
Package: nfs-common
Version: 1.2.6-4
NFS with sec=krb5i or sec=krb5p using MIT Kerberos does not work when
cross-realm authentication is used -- only when clients have an
Kerberos ticket for the same realm. This happens consistently and in
cases when cross-realm authentication does work with other services on
the same machine, such as SSH.
To illustrate, I've included two sets of NFS debug output from both a
client (daboia.dapadam.nl) and a server (cerastes.dapadam.nl): one set
with a successful authentication and the other with a failure. The
first set involves a user, jwinius, with an MIT Kerberos ticket from
the same realm, DAPADAM.NL, that results in a successful authentication:
=== Begin === Success, client log output =================
Jul 1 16:08:37 daboia rpc.gssd[1422]: handling gssd upcall
(/var/lib/nfs/rpc_pipefs/nfs/clnt0)
Jul 1 16:08:37 daboia rpc.gssd[1422]: handle_gssd_upcall: 'mech=krb5
uid=10000 enctypes=18,17,16,23,3,1,2 '
Jul 1 16:08:37 daboia rpc.gssd[1422]: handling krb5 upcall
(/var/lib/nfs/rpc_pipefs/nfs/clnt0)
Jul 1 16:08:37 daboia rpc.gssd[1422]: process_krb5_upcall: service is
'<null>'
Jul 1 16:08:37 daboia rpc.gssd[1422]: getting credentials for client
with uid 10000 for server cerastes.dapadam.nl
Jul 1 16:08:37 daboia rpc.gssd[1422]: CC file
'/tmp/krb5cc_0_8TcUINGCct' being considered, with preferred realm
'DAPADAM.NL'
Jul 1 16:08:37 daboia rpc.gssd[1422]: CC file
'/tmp/krb5cc_0_8TcUINGCct' owned by 0, not 10000
Jul 1 16:08:37 daboia rpc.gssd[1422]: CC file
'/tmp/krb5cc_machine_DAPADAM.NL' being considered, with preferred
realm 'DAPADAM.NL'
Jul 1 16:08:37 daboia rpc.gssd[1422]: CC file
'/tmp/krb5cc_machine_DAPADAM.NL' owned by 0, not 10000
Jul 1 16:08:37 daboia rpc.gssd[1422]: CC file
'/tmp/krb5cc_10000_HFd9c1oOJy' being considered, with preferred realm
'DAPADAM.NL'
Jul 1 16:08:37 daboia rpc.gssd[1422]: CC file
'/tmp/krb5cc_10000_HFd9c1oOJy'(jwin...@dapadam.nl) passed all checks
and has mtime of 1404223701
Jul 1 16:08:37 daboia rpc.gssd[1422]: CC file '/tmp/krb5cc_0' being
considered, with preferred realm 'DAPADAM.NL'
Jul 1 16:08:37 daboia rpc.gssd[1422]: CC file '/tmp/krb5cc_0' owned
by 0, not 10000
Jul 1 16:08:37 daboia rpc.gssd[1422]: using
FILE:/tmp/krb5cc_10000_HFd9c1oOJy as credentials cache for client with
uid 10000 for server cerastes.dapadam.nl
Jul 1 16:08:37 daboia rpc.gssd[1422]: using environment variable to
select krb5 ccache FILE:/tmp/krb5cc_10000_HFd9c1oOJy
Jul 1 16:08:37 daboia rpc.gssd[1422]: creating context using fsuid
10000 (save_uid 0)
Jul 1 16:08:37 daboia rpc.gssd[1422]: creating tcp client for server
cerastes.dapadam.nl
Jul 1 16:08:37 daboia rpc.gssd[1422]: DEBUG: port already set to 2049
Jul 1 16:08:37 daboia rpc.gssd[1422]: creating context with server
n...@cerastes.dapadam.nl
Jul 1 16:08:37 daboia rpc.gssd[1422]: DEBUG: serialize_krb5_ctx:
lucid version!
Jul 1 16:08:37 daboia rpc.gssd[1422]: prepare_krb5_rfc4121_buffer: protocol 1
Jul 1 16:08:37 daboia rpc.gssd[1422]: prepare_krb5_rfc4121_buffer:
serializing key with enctype 18 and size 32
Jul 1 16:08:37 daboia rpc.gssd[1422]: doing downcall
Jul 1 16:08:37 daboia rpc.idmapd[1417]: nfs4_name_to_uid: calling
nsswitch->name_to_uid
Jul 1 16:08:37 daboia rpc.idmapd[1417]: nss_getpwnam: name
'jwin...@dapadam.nl' domain 'dapadam.nl': resulting localname 'jwinius'
Jul 1 16:08:37 daboia rpc.idmapd[1417]: nfs4_name_to_uid:
nsswitch->name_to_uid returned 0
Jul 1 16:08:37 daboia rpc.idmapd[1417]: nfs4_name_to_uid: final
return value is 0
Jul 1 16:08:37 daboia rpc.idmapd[1417]: Client 0: (user) name
"jwin...@dapadam.nl" -> id "10000"
Jul 1 16:08:37 daboia rpc.idmapd[1417]: nfs4_name_to_gid: calling
nsswitch->name_to_gid
Jul 1 16:08:37 daboia rpc.idmapd[1417]: nfs4_name_to_gid:
nsswitch->name_to_gid returned 0
Jul 1 16:08:37 daboia rpc.idmapd[1417]: nfs4_name_to_gid: final
return value is 0
Jul 1 16:08:37 daboia rpc.idmapd[1417]: Client 0: (group) name
"jwin...@dapadam.nl" -> id "10000"
Jul 1 16:08:37 daboia rpc.gssd[1422]: dir_notify_handler: sig 37 si
0x7fff3cdee670 data 0x7fff3cdee540
Jul 1 16:08:37 daboia rpc.idmapd[1417]: New client: 2
Jul 1 16:17:01 daboia /USR/SBIN/CRON[2399]: (root) CMD ( cd / &&
run-parts --report /etc/cron.hourly)
=== End ===== Success, client log output =================
=== Begin === Success, server log output =================
Jul 1 16:08:37 cerastes rpc.svcgssd[3295]: leaving poll
Jul 1 16:08:37 cerastes rpc.svcgssd[3295]: handling null request
Jul 1 16:08:37 cerastes rpc.svcgssd[3295]:
svcgssd_limit_krb5_enctypes: Calling gss_set_allowable_enctypes with 7
enctypes from the kernel
Jul 1 16:08:37 cerastes rpc.svcgssd[3295]: sname = jwin...@dapadam.nl
Jul 1 16:08:37 cerastes rpc.svcgssd[3295]: DEBUG: serialize_krb5_ctx:
lucid version!
Jul 1 16:08:37 cerastes rpc.svcgssd[3295]:
prepare_krb5_rfc4121_buffer: protocol 1
Jul 1 16:08:37 cerastes rpc.svcgssd[3295]:
prepare_krb5_rfc4121_buffer: serializing key with enctype 18 and size 32
Jul 1 16:08:37 cerastes rpc.svcgssd[3295]: doing downcall
Jul 1 16:08:37 cerastes rpc.svcgssd[3295]: mech: krb5, hndl len: 4,
ctx len 52, timeout: 1404310094 (86377 from now), clnt: <null>, uid:
10000, gid: 10000, num
Jul 1 16:08:37 cerastes rpc.svcgssd[3295]: ( 1) 10000
Jul 1 16:08:37 cerastes rpc.svcgssd[3295]: sending null reply
Jul 1 16:08:37 cerastes rpc.svcgssd[3295]: writing message: \x
\x6082025806092a864886f71201020201006e82024730820243a003020105a10302010ea20703050020000000a38201
Jul 1 16:08:37 cerastes rpc.svcgssd[3295]: finished handling null request
Jul 1 16:08:37 cerastes rpc.svcgssd[3295]: entering poll
Jul 1 16:08:37 cerastes rpc.idmapd[1579]: nfsdcb: authbuf=gss/krb5i
authtype=user
Jul 1 16:08:37 cerastes rpc.idmapd[1579]: nfs4_uid_to_name: calling
nsswitch->uid_to_name
Jul 1 16:08:37 cerastes rpc.idmapd[1579]: nfs4_uid_to_name:
nsswitch->uid_to_name returned 0
Jul 1 16:08:37 cerastes rpc.idmapd[1579]: nfs4_uid_to_name: final
return value is 0
Jul 1 16:08:37 cerastes rpc.idmapd[1579]: Server : (user) id "0" ->
name "r...@dapadam.nl"
Jul 1 16:08:37 cerastes rpc.idmapd[1579]: nfsdcb: authbuf=gss/krb5i
authtype=group
Jul 1 16:08:37 cerastes rpc.idmapd[1579]: nfs4_gid_to_name: calling
nsswitch->gid_to_name
Jul 1 16:08:37 cerastes rpc.idmapd[1579]: nfs4_gid_to_name:
nsswitch->gid_to_name returned 0
Jul 1 16:08:37 cerastes rpc.idmapd[1579]: nfs4_gid_to_name: final
return value is 0
Jul 1 16:08:37 cerastes rpc.idmapd[1579]: Server : (group) id "0" ->
name "r...@dapadam.nl"
Jul 1 16:08:37 cerastes rpc.idmapd[1579]: nfsdcb: authbuf=gss/krb5i
authtype=user
Jul 1 16:08:37 cerastes rpc.idmapd[1579]: nfs4_uid_to_name: calling
nsswitch->uid_to_name
Jul 1 16:08:37 cerastes rpc.idmapd[1579]: nfs4_uid_to_name:
nsswitch->uid_to_name returned 0
Jul 1 16:08:37 cerastes rpc.idmapd[1579]: nfs4_uid_to_name: final
return value is 0
Jul 1 16:08:37 cerastes rpc.idmapd[1579]: Server : (user) id "10000"
-> name "jwin...@dapadam.nl"
Jul 1 16:08:37 cerastes rpc.idmapd[1579]: nfsdcb: authbuf=gss/krb5i
authtype=group
Jul 1 16:08:37 cerastes rpc.idmapd[1579]: nfs4_gid_to_name: calling
nsswitch->gid_to_name
Jul 1 16:08:37 cerastes rpc.idmapd[1579]: nfs4_gid_to_name:
nsswitch->gid_to_name returned 0
Jul 1 16:08:37 cerastes rpc.idmapd[1579]: nfs4_gid_to_name: final
return value is 0
Jul 1 16:08:37 cerastes rpc.idmapd[1579]: Server : (group) id "10000"
-> name "jwin...@dapadam.nl"
Jul 1 16:17:01 cerastes /USR/SBIN/CRON[3331]: (root) CMD ( cd / &&
run-parts --report /etc/cron.hourly)
=== End ===== Success, server log output =================
The second set involves a user account with the same name, jwinius,
but with a Kerberos ticket from a different, albeit trusted realm:
UMRK.NL. This always results in an authentication failure:
=== Begin === Failure, client log output =================
Jul 1 16:22:19 daboia rpc.gssd[1423]: handling gssd upcall
(/var/lib/nfs/rpc_pipefs/nfs/clnt0)
Jul 1 16:22:19 daboia rpc.gssd[1423]: handle_gssd_upcall: 'mech=krb5
uid=10000 enctypes=18,17,16,23,3,1,2 '
Jul 1 16:22:19 daboia rpc.gssd[1423]: handling krb5 upcall
(/var/lib/nfs/rpc_pipefs/nfs/clnt0)
Jul 1 16:22:19 daboia rpc.gssd[1423]: process_krb5_upcall: service is
'<null>'
Jul 1 16:22:19 daboia rpc.gssd[1423]: getting credentials for client
with uid 10000 for server cerastes.dapadam.nl
Jul 1 16:22:19 daboia rpc.gssd[1423]: CC file
'/tmp/krb5cc_machine_DAPADAM.NL' being considered, with preferred
realm 'DAPADAM.NL'
Jul 1 16:22:19 daboia rpc.gssd[1423]: CC file
'/tmp/krb5cc_machine_DAPADAM.NL' owned by 0, not 10000
Jul 1 16:22:19 daboia rpc.gssd[1423]: CC file
'/tmp/krb5cc_10000_goDYeANk0D' being considered, with preferred realm
'DAPADAM.NL'
Jul 1 16:22:19 daboia rpc.gssd[1423]: CC file
'/tmp/krb5cc_10000_goDYeANk0D'(jwin...@umrk.nl) passed all checks and
has mtime of 1404224533
Jul 1 16:22:19 daboia rpc.gssd[1423]: CC file
'/tmp/krb5cc_0_emiVRCT1ma' being considered, with preferred realm
'DAPADAM.NL'
Jul 1 16:22:19 daboia rpc.gssd[1423]: CC file
'/tmp/krb5cc_0_emiVRCT1ma' owned by 0, not 10000
Jul 1 16:22:19 daboia rpc.gssd[1423]: CC file '/tmp/krb5cc_0' being
considered, with preferred realm 'DAPADAM.NL'
Jul 1 16:22:19 daboia rpc.gssd[1423]: CC file '/tmp/krb5cc_0' owned
by 0, not 10000
Jul 1 16:22:19 daboia rpc.gssd[1423]: using
FILE:/tmp/krb5cc_10000_goDYeANk0D as credentials cache for client with
uid 10000 for server cerastes.dapadam.nl
Jul 1 16:22:19 daboia rpc.gssd[1423]: using environment variable to
select krb5 ccache FILE:/tmp/krb5cc_10000_goDYeANk0D
Jul 1 16:22:19 daboia rpc.gssd[1423]: creating context using fsuid
10000 (save_uid 0)
Jul 1 16:22:19 daboia rpc.gssd[1423]: creating tcp client for server
cerastes.dapadam.nl
Jul 1 16:22:19 daboia rpc.gssd[1423]: DEBUG: port already set to 2049
Jul 1 16:22:19 daboia rpc.gssd[1423]: creating context with server
n...@cerastes.dapadam.nl
Jul 1 16:22:19 daboia rpc.gssd[1423]: DEBUG: serialize_krb5_ctx:
lucid version!
Jul 1 16:22:19 daboia rpc.gssd[1423]: prepare_krb5_rfc4121_buffer: protocol 1
Jul 1 16:22:19 daboia rpc.gssd[1423]: prepare_krb5_rfc4121_buffer:
serializing key with enctype 18 and size 32
Jul 1 16:22:19 daboia rpc.gssd[1423]: doing downcall
Jul 1 16:22:19 daboia rpc.idmapd[1418]: nfs4_name_to_uid: calling
nsswitch->name_to_uid
Jul 1 16:22:19 daboia rpc.idmapd[1418]: nss_getpwnam: name
'jwin...@dapadam.nl' domain 'dapadam.nl': resulting localname 'jwinius'
Jul 1 16:22:19 daboia rpc.idmapd[1418]: nfs4_name_to_uid:
nsswitch->name_to_uid returned 0
Jul 1 16:22:19 daboia rpc.idmapd[1418]: nfs4_name_to_uid: final
return value is 0
Jul 1 16:22:19 daboia rpc.idmapd[1418]: Client 0: (user) name
"jwin...@dapadam.nl" -> id "10000"
Jul 1 16:22:19 daboia rpc.idmapd[1418]: nfs4_name_to_gid: calling
nsswitch->name_to_gid
Jul 1 16:22:19 daboia rpc.idmapd[1418]: nfs4_name_to_gid:
nsswitch->name_to_gid returned 0
Jul 1 16:22:19 daboia rpc.idmapd[1418]: nfs4_name_to_gid: final
return value is 0
Jul 1 16:22:19 daboia rpc.idmapd[1418]: Client 0: (group) name
"jwin...@dapadam.nl" -> id "10000"
Jul 1 16:22:19 daboia rpc.gssd[1423]: dir_notify_handler: sig 37 si
0x7fffcbbd9ef0 data 0x7fffcbbd9dc0
Jul 1 16:22:19 daboia rpc.idmapd[1418]: New client: 2
=== End ===== Failure, client log output =================
=== Begin === Failure, server log output =================
Jul 1 16:22:18 cerastes rpc.svcgssd[3295]: leaving poll
Jul 1 16:22:18 cerastes rpc.svcgssd[3295]: handling null request
Jul 1 16:22:18 cerastes rpc.svcgssd[3295]:
svcgssd_limit_krb5_enctypes: Calling gss_set_allowable_enctypes with 7
enctypes from the kernel
Jul 1 16:22:18 cerastes rpc.svcgssd[3295]: sname = jwin...@umrk.nl
Jul 1 16:22:18 cerastes rpc.svcgssd[3295]: nss_gss_princ_to_ids:
Local-Realm 'UMRK.NL': NOT FOUND
Jul 1 16:22:18 cerastes rpc.svcgssd[3295]: DEBUG: serialize_krb5_ctx:
lucid version!
Jul 1 16:22:18 cerastes rpc.svcgssd[3295]:
prepare_krb5_rfc4121_buffer: protocol 1
Jul 1 16:22:18 cerastes rpc.svcgssd[3295]:
prepare_krb5_rfc4121_buffer: serializing key with enctype 18 and size 32
Jul 1 16:22:18 cerastes rpc.svcgssd[3295]: doing downcall
Jul 1 16:22:18 cerastes rpc.svcgssd[3295]: mech: krb5, hndl len: 4,
ctx len 52, timeout: 1404299912 (75374 from now), clnt: <null>, uid:
-1, gid: -1, num aux g
Jul 1 16:22:18 cerastes rpc.svcgssd[3295]: sending null reply
Jul 1 16:22:18 cerastes rpc.svcgssd[3295]: writing message: \x
\x6082025106092a864886f71201020201006e8202403082023ca003020105a10302010ea20703050020000000a38201
Jul 1 16:22:18 cerastes rpc.svcgssd[3295]: finished handling null request
Jul 1 16:22:18 cerastes rpc.svcgssd[3295]: entering poll
Jul 1 16:22:18 cerastes rpc.idmapd[1579]: nfsdcb: authbuf=gss/krb5i
authtype=user
Jul 1 16:22:18 cerastes rpc.idmapd[1579]: nfs4_uid_to_name: calling
nsswitch->uid_to_name
Jul 1 16:22:18 cerastes rpc.idmapd[1579]: nfs4_uid_to_name:
nsswitch->uid_to_name returned 0
Jul 1 16:22:18 cerastes rpc.idmapd[1579]: nfs4_uid_to_name: final
return value is 0
Jul 1 16:22:18 cerastes rpc.idmapd[1579]: Server : (user) id "10000"
-> name "jwin...@dapadam.nl"
Jul 1 16:22:18 cerastes rpc.idmapd[1579]: nfsdcb: authbuf=gss/krb5i
authtype=group
Jul 1 16:22:18 cerastes rpc.idmapd[1579]: nfs4_gid_to_name: calling
nsswitch->gid_to_name
Jul 1 16:22:18 cerastes rpc.idmapd[1579]: nfs4_gid_to_name:
nsswitch->gid_to_name returned 0
Jul 1 16:22:18 cerastes rpc.idmapd[1579]: nfs4_gid_to_name: final
return value is 0
Jul 1 16:22:18 cerastes rpc.idmapd[1579]: Server : (group) id "10000"
-> name "jwin...@dapadam.nl"
=== End ===== Failure, server log output =================
The user experience ends with a "Permission denied" message, although
the client does receive a Kerberos service ticket despite the failure.
The rpc.idmapd daemon seems to translate the jwin...@umrk.nl account
to "jwin...@dapadam.nl" with user ID 10000. In some situations this
might be incorrect, but here it's okay because both accounts belong to
the same person.
When authentication fails, the only evidence that I can see for this
in the server's log output is in the fifth line shown:
"nss_gss_princ_to_ids: Local-Realm 'UMRK.NL': NOT FOUND". Apparently,
the local Kerberos KDC is not interrogated and the trust entry for the
UMRK.NL realm is never discovered.
For both machines, the verbosity for rpc.idmapd was set to 5, rpc.gssd
was used with the options "-D -vvvvvvvvvv" (see Debian bug report
#728255 for why I use -D) and rpc.svcgssd was run with the option
"-vvvvvvvvvv". The rpc.mountd daemon was also running (with option
"--port 32767"), but rpc.statd was disabled. Moreover, I generally get
better results when running rpc.svcgssd on the client as well as the
server; this daemon is actually part of the nfs-common package,
although the startup script does not yet reflect this and needs to be
modified for it to start on the client.
--- End Message ---
--- Begin Message ---
Hi
[This reply and bug closer is sent for doing BTS maintenance for
src:nfs-utils bugs]
This bug was reported against a very old nfs-utils version without much
followups/triaging itself.
If you can reproduce it with the current version in unstable/testing or
stable at least, please reopen the bug,
https://www.debian.org/Bugs/server-control for details.
Regards,
Salvatore
--- End Message ---
