search

gssapi / gssproxy

A proxy for GSSAPI | Docs at https://github.com/gssapi/gssproxy/tree/main/docs
Other
44 stars 28 forks source link

Multi-homed NFS client does not select correct service principal #65

Open chucklever opened 2 years ago

chucklever commented 2 years ago

The NFSv4.0 callback client in the Linux NFS server invokes gssproxy (somehow) to acquire the credential for its callback channel.

On multi-homed systems, GSSX_ARG_ACQUIRE_CRED always selects the principal associated with "uname -n". When creating an NFS client on alternate network interfaces, GSSX_ARG_ACQUIRE_CRED needs to select the principal associated with that interface, not the one associated with "uname -n".

simo5 commented 2 years ago

The target is generally controlled by the calling code.

In this case I assume rpc.gssd is being invoked. Gss-proxy has no idea what interface is used because it is removed from direct knowledge of which interfaces its client is working with.

Can you identify exactly what path is being used? setting debug log to level 3 and providing a trace of the failing callback would help determine if this is something that can be dealt with configuration or if it is the calling code that needs to be adjusted.

simo5 commented 2 years ago

Just to be clear gssproxy does not use uname -a, either it gets a gss_name for the credential to acquire, or it will parse the keytab and select the first appropriate principal. Unless the krb5_principal option is set, in which case it will try that if no gss_name is being passed in by the caller.

chucklever commented 2 years ago

I can't tell who is making the request to acquire the credential. gssd appears to have the correct principal name: "manet.ib.1015granger.net" but the argument for the ACQUIRE_CRED call is "manet.1015granger.net". I can't determine who is the caller. (This is from an earlier session; I can't recall if debug_level was set to 2 or 3 at this time).

Sep 20 10:19:16 manet.1015granger.net rpc.gssd[1004]: creating client nfsd4_cb/clnt28
Sep 20 10:19:16 manet.1015granger.net rpc.gssd[1004]: scanning client nfsd4_cb/clnt28
Sep 20 10:19:16 manet.1015granger.net rpc.gssd[1004]: destroying client nfsd4_cb/clnt27
Sep 20 10:19:16 manet.1015granger.net rpc.gssd[1004]: freeing client nfsd4_cb/clnt27
Sep 20 10:19:16 manet.1015granger.net rpc.gssd[1004]: 
                                                      handle_gssd_upcall(0x7fdebd2f5840): 'mech=krb5 uid=0 target=nfs@morisot.1015granger.net service=nfs srchost=manet.ib.1015granger.net enctypes=18,17,16,3,1,2' (nfsd4_cb/clnt28)
Sep 20 10:19:16 manet.1015granger.net rpc.gssd[1004]: start_upcall_thread(0x7fdebd2f5840): created thread id 0x7fdeb6ffd640
Sep 20 10:19:16 manet.1015granger.net rpc.gssd[1004]: krb5_use_machine_creds(0x7fdeb6ffd640): uid 0 tgtname nfs@morisot.1015granger.net
Sep 20 10:19:16 manet.1015granger.net rpc.gssd[1004]: find_keytab_entry(0x7fdeb6ffd640): Success getting keytab entry for 'nfs/manet.ib.1015granger.net@1015GRANGER.NET'
Sep 20 10:19:16 manet.1015granger.net rpc.gssd[1004]: gssd_get_single_krb5_cred(0x7fdeb6ffd640): Credentials in CC 'FILE:/tmp/krb5ccmachine_1015GRANGER.NET' are good until Tue Sep 20 16:35:20 2022
Sep 20 10:19:16 manet.1015granger.net rpc.gssd[1004]: gssd_get_single_krb5_cred(0x7fdeb6ffd640): Credentials in CC 'FILE:/tmp/krb5ccmachine_1015GRANGER.NET' are good until Tue Sep 20 16:14:07 2022
Sep 20 10:19:16 manet.1015granger.net rpc.gssd[1004]: gssd_get_single_krb5_cred(0x7fdeb6ffd640): Credentials in CC 'FILE:/tmp/krb5ccmachine_1015GRANGER.NET' are good until Tue Sep 20 16:35:20 2022
Sep 20 10:19:16 manet.1015granger.net gssproxy[996]: [CID 11][2022/09/20 14:19:16]: Connection matched service nfs-client
Sep 20 10:19:16 manet.1015granger.net gssproxy[996]: [CID 11][2022/09/20 14:19:16]: gp_rpc_execute: executing 6 (GSSX_ACQUIRE_CRED) for service "nfs-client", euid: 0,socket: (null)
Sep 20 10:19:16 manet.1015granger.net gssproxy[996]:     GSSX_ARG_ACQUIRE_CRED( call_ctx: { "" [  ] } input_cred_handle: { "nfs/manet.1015granger.net@1015GRANGER.NET" [ { "nfs/manet.1015granger.net@1015GRANGER.NET" { 1 2 840 113554 1 2 2 } INITIATE 83137 0 } ] [ ...........Q0...... ] 0 } add_cred: 0 desired_name: <Null> time_req: 4294967295 desired_mechs: { { 1 2 840 113554 1 2 2 } } cred_usage: INITIATE initiator_time_req: 0 acceptor_time_req: 0 )
Sep 20 10:19:16 manet.1015granger.net gssproxy[996]:     GSSX_RES_ACQUIRE_CRED( status: { 0 { 1 2 840 113554 1 2 2 } 0 "" "" [  ] } output_cred_handle: { "nfs/manet.1015granger.net@1015GRANGER.NET" [ { "nfs/manet.1015granger.net@1015GRANGER.NET" { 1 2 840 113554 1 2 2 } INITIATE 83137 0 } ] [ ...........Q0...... ] 0 } )
Sep 20 10:19:16 manet.1015granger.net rpc.gssd[1004]: create_auth_rpc_client(0x7fdeb6ffd640): creating tcp client for server morisot.ib.1015granger.net
Sep 20 10:19:16 manet.1015granger.net rpc.gssd[1004]: DEBUG: port already set to 37259
Sep 20 10:19:16 manet.1015granger.net rpc.gssd[1004]: create_auth_rpc_client(0x7fdeb6ffd640): creating context with server nfs@morisot.1015granger.net
Sep 20 10:19:16 manet.1015granger.net gssproxy[996]: [CID 11][2022/09/20 14:19:16]: Connection matched service nfs-client
Sep 20 10:19:16 manet.1015granger.net gssproxy[996]: [CID 11][2022/09/20 14:19:16]: gp_rpc_execute: executing 8 (GSSX_INIT_SEC_CONTEXT) for service "nfs-client", euid: 0,socket: (null)
Sep 20 10:19:16 manet.1015granger.net gssproxy[996]:     GSSX_ARG_INIT_SEC_CONTEXT( call_ctx: { "" [  ] } context_handle: <Null> cred_handle: { "nfs/manet.1015granger.net@1015GRANGER.NET" [ { "nfs/manet.1015granger.net@1015GRANGER.NET" { 1 2 840 113554 1 2 2 } INITIATE 83137 0 [ { [ krb5.set.allowed... ] [ ................... ] } ] } ] [ ...........Q0...... ] 0 } target_name: "nfs@morisot.1015granger.net" mech_type: { 1 2 840 113554 1 2 2 } req_flags: 2 time_req: 0 input_cb: <Null> input_token: <Null> [ { [ sync.modified.cr... ] [ 64656661756c740 ] } ] )
Sep 20 10:19:16 manet.1015granger.net gssproxy[996]: [CID 11][2022/09/20 14:19:16]: Credentials allowed by configuration
Sep 20 10:19:16 manet.1015granger.net gssproxy[996]:     GSSX_RES_INIT_SEC_CONTEXT( status: { 1 { 1 2 840 113554 1 2 2 } 0 "The routine must be called again to complete its function" "" [  ] } context_handle: { [ ......H............ ] [  ] 0 { 1 2 840 113554 1 2 2 } "" "" 0 306 1 0 } output_token: [ ........H.......... ] )
Sep 20 10:19:16 manet.1015granger.net gssproxy[996]: [CID 11][2022/09/20 14:19:16]: Connection matched service nfs-client
Sep 20 10:19:16 manet.1015granger.net gssproxy[996]: [CID 11][2022/09/20 14:19:16]: gp_rpc_execute: executing 8 (GSSX_INIT_SEC_CONTEXT) for service "nfs-client", euid: 0,socket: (null)
Sep 20 10:19:16 manet.1015granger.net gssproxy[996]:     GSSX_ARG_INIT_SEC_CONTEXT( call_ctx: { "" [  ] } context_handle: { [ ......H............ ] [  ] 0 { 1 2 840 113554 1 2 2 } "" "" 0 306 1 0 } cred_handle: { "nfs/manet.1015granger.net@1015GRANGER.NET" [ { "nfs/manet.1015granger.net@1015GRANGER.NET" { 1 2 840 113554 1 2 2 } INITIATE 83137 0 [ { [ krb5.set.allowed... ] [ ................... ] } ] } ] [ ...........Q0...... ] 0 } target_name: "nfs@morisot.1015granger.net" mech_type: { 1 2 840 113554 1 2 2 } req_flags: 2 time_req: 0 input_cb: <Null> input_token: [ .......H........... ] [ { [ sync.modified.cr... ] [ 64656661756c740 ] } ] )
Sep 20 10:19:16 manet.1015granger.net gssproxy[996]: [CID 11][2022/09/20 14:19:16]: Credentials allowed by configuration
Sep 20 10:19:16 manet.1015granger.net gssproxy[996]:     GSSX_RES_INIT_SEC_CONTEXT( status: { 0 { 1 2 840 113554 1 2 2 } 0 "" "" [  ] } context_handle: { [ ......H............ ] [  ] 0 { 1 2 840 113554 1 2 2 } "nfs/manet.1015granger.net@1015GRANGER.NET" "nfs/morisot.1015granger.net@1015GRANGER.NET" 15308 306 1 1 } output_token: <Null> )
Sep 20 10:19:16 manet.1015granger.net rpc.gssd[1004]: DEBUG: serialize_krb5_ctx: lucid version!
Sep 20 10:19:16 manet.1015granger.net rpc.gssd[1004]: prepare_krb5_rfc4121_buffer: protocol 1
Sep 20 10:19:16 manet.1015granger.net rpc.gssd[1004]: prepare_krb5_rfc4121_buffer: serializing key with enctype 18 and size 32
Sep 20 10:19:16 manet.1015granger.net rpc.gssd[1004]: do_downcall(0x7fdeb6ffd640): lifetime_rec=4h:15m:8s acceptor=nfs@morisot.1015granger.net
simo5 commented 2 years ago

Ths is the caller: Sep 20 10:19:16 manet.1015granger.net rpc.gssd[1004]: gssd_get_single_krb5_cred(0x7fdeb6ffd640): Credentials in CC 'FILE:/tmp/krb5ccmachine_1015GRANGER.NET' are good until Tue Sep 20 16:35:20 2022

rpc.gssd process 1004

Do not know why rpc.gssd is crawling the keytab and then calling the wrong name.

can you: klist -kt /et/krb5.keytab ? (or whatever file the keytab is in)

chucklever commented 2 years ago

It's a mystery. find_keytab_entry() claims to be picking up nfs/manet.ib.1015granger.net, which is the correct principal for this context.

[root@manet ~]# klist -ke
Keytab name: FILE:/etc/krb5.keytab
KVNO Principal
---- --------------------------------------------------------------------------
   1 nfs/manet.1015granger.net@1015GRANGER.NET (aes256-cts-hmac-sha1-96) 
   1 nfs/manet.1015granger.net@1015GRANGER.NET (aes128-cts-hmac-sha1-96) 
   1 nfs/manet.ib.1015granger.net@1015GRANGER.NET (aes256-cts-hmac-sha1-96) 
   1 nfs/manet.ib.1015granger.net@1015GRANGER.NET (aes128-cts-hmac-sha1-96) 
[root@manet ~]#
chucklever commented 2 years ago

I added a debugging printf just after the krb5_unparse_name() call site in gssd_get_single_krb5_cred(). Seems to confirm that gssd has the correct principal name.

Sep 20 14:36:06 manet.1015granger.net rpc.gssd[996]: cel: principal 'nfs/manet.ib.1015granger.net@1015GRANGER.NET' using keytab 'FILE:/etc/krb5.keytab'
simo5 commented 2 years ago

Can you point me at the place you see this in the code? a quick glance I do not see a place where gss_acquire_cred() is called from rpc.gssd with a target name.

chucklever commented 2 years ago

I've instrumented gssd. gssd_get_single_krb5_cred() invokes the library function krb5_get_init_creds_keytab() with the longer, correct principal as the third argument. Subsequently I see in the log the GSSX_ARG_ACQUIRE_CRED call with the shorter, incorrect principal.

So at this point I believe that gssd is not invoking gss_acquire_cred() directly for client side context establishment.

simo5 commented 2 years ago

That's what I thought, this is a gssd bug. gssproxy can try to paper over some things, but it can't divine which, of multiple principals, the application want's to use.

chucklever commented 2 years ago

Not a gssd bug, it’s a library bug. As I said, gssd provides the exact principal it wants to krb5_get_init_creds_keytab().

simo5 commented 2 years ago

If you open a bug somwhere against it would be nice if you could link it here, so I can turn this issue into a discussion for other with the same issue to discover.

chucklever commented 2 years ago

Understood. I'm first looking for possible library configuration settings that might help.

chucklever commented 2 years ago

Fedora bugzilla 2128804 has been filed to seek assistance with debugging the mysterious API behavior.