727629 – nfs-utils-1.2.3-7 breaks nfs4 mounting with krb5 security

Bug 727629 - nfs-utils-1.2.3-7 breaks nfs4 mounting with krb5 security

Summary: nfs-utils-1.2.3-7 breaks nfs4 mounting with krb5 security

Keywords:
Status:	CLOSED DUPLICATE of bug 720479
Alias:	None
Product:	Red Hat Enterprise Linux 6
Classification:	Red Hat
Component:	nfs-utils
Sub Component:
Version:	6.1
Hardware:	Unspecified
OS:	Unspecified
Priority:	unspecified
Severity:	unspecified
Target Milestone:	rc
Target Release:	---
Assignee:	Steve Dickson
QA Contact:	yanfu,wang
Docs Contact:
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+	depends on / blocked

Reported:	2011-08-02 16:29 UTC by Jonathan Underwood
Modified:	2011-08-16 11:48 UTC (History)
CC List:	2 users (show)
Fixed In Version:
Doc Type:	Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed:	2011-08-16 11:48:37 UTC
Target Upstream Version:

Attachments	(Terms of Use)
Add an attachment (proposed patch, testcase, etc.)

Description Jonathan Underwood 2011-08-02 16:29:42 UTC

Description of problem:
Having upgraded a client machine to 6.1, I am no longer able to mount nfs4 shares requiring kerberos tickets. If i downgrade just the nfs-utils package to nfs-utils-1.2.2-7 from (6.0) then all works again.

Version-Release number of selected component (if applicable):
nfs-utils-1.2.3-7

How reproducible:
Everytime

with the -v -v -v options passed to rpcgssd on the client machine, I see the following in /var/log/messages for nfs-utils-1.2.3-7:

Aug  2 16:19:58 burroughs rpc.gssd[3390]: dir_notify_handler: sig 37 si 0x7fff19c6e2b0 data 0x7fff19c6e180
Aug  2 16:19:58 burroughs rpc.gssd[3390]: dir_notify_handler: sig 37 si 0x7fff19c69770 data 0x7fff19c69640
Aug  2 16:19:58 burroughs rpc.gssd[3390]: dir_notify_handler: sig 37 si 0x7fff19c6e2b0 data 0x7fff19c6e180
Aug  2 16:19:58 burroughs rpc.gssd[3390]: handling gssd upcall (/var/lib/nfs/rpc_pipefs/nfs/clnta)
Aug  2 16:19:58 burroughs rpc.gssd[3390]: handle_gssd_upcall: 'mech=krb5 uid=0 enctypes=18,17,16,23,3,1,2 '
Aug  2 16:19:58 burroughs rpc.gssd[3390]: handling krb5 upcall (/var/lib/nfs/rpc_pipefs/nfs/clnta)
Aug  2 16:19:58 burroughs rpc.gssd[3390]: process_krb5_upcall: service is '<null>'
Aug  2 16:19:58 burroughs rpc.gssd[3390]: Full hostname for 'oaxaca.theory.phys.ucl.ac.uk' is 'oaxaca.theory.phys.ucl.ac.uk'
Aug  2 16:19:58 burroughs rpc.gssd[3390]: Full hostname for 'burroughs.theory.phys.ucl.ac.uk' is 'burroughs.theory.phys.ucl.ac.uk'
Aug  2 16:19:58 burroughs rpc.gssd[3390]: No key table entry found for BURROUGHS.THEORY.PHYS.UCL.AC.UK$@THEORY.PHYS.UCL.AC.UK while getting keyta
b entry for 'BURROUGHS.THEORY.PHYS.UCL.AC.UK$@THEORY.PHYS.UCL.AC.UK'
Aug  2 16:19:58 burroughs rpc.gssd[3390]: No key table entry found for root/burroughs.theory.phys.ucl.ac.uk.UCL.AC.UK while getting k
eytab entry for 'root/burroughs.theory.phys.ucl.ac.uk.UCL.AC.UK'
Aug  2 16:19:58 burroughs rpc.gssd[3390]: Success getting keytab entry for 'nfs/burroughs.theory.phys.ucl.ac.uk.UCL.AC.UK'
Aug  2 16:19:58 burroughs rpc.gssd[3390]: INFO: Credentials in CC 'FILE:/tmp/krb5cc_machine_THEORY.PHYS.UCL.AC.UK' are good until 1312383729
Aug  2 16:19:58 burroughs rpc.gssd[3390]: INFO: Credentials in CC 'FILE:/tmp/krb5cc_machine_THEORY.PHYS.UCL.AC.UK' are good until 1312383729
Aug  2 16:19:58 burroughs rpc.gssd[3390]: using FILE:/tmp/krb5cc_machine_THEORY.PHYS.UCL.AC.UK as credentials cache for machine creds
Aug  2 16:19:58 burroughs rpc.gssd[3390]: using environment variable to select krb5 ccache FILE:/tmp/krb5cc_machine_THEORY.PHYS.UCL.AC.UK
Aug  2 16:19:58 burroughs rpc.gssd[3390]: creating context using fsuid 0 (save_uid 0)
Aug  2 16:19:58 burroughs rpc.gssd[3390]: ERROR: GSS-API: error in gss_set_allowable_enctypes(): GSS_S_NO_CRED (No credentials were supplied, or 
the credentials were unavailable or inaccessible) - Unknown error
Aug  2 16:19:58 burroughs rpc.gssd[3390]: WARNING: Failed while limiting krb5 encryption types for user with uid 0
Aug  2 16:19:58 burroughs rpc.gssd[3390]: WARNING: Failed to create machine krb5 context with credentials cache FILE:/tmp/krb5cc_machine_THEORY.P
HYS.UCL.AC.UK for server oaxaca.theory.phys.ucl.ac.uk
Aug  2 16:19:58 burroughs rpc.gssd[3390]: WARNING: Machine cache is prematurely expired or corrupted trying to recreate cache for server oaxaca.t
heory.phys.ucl.ac.uk
Aug  2 16:19:58 burroughs rpc.gssd[3390]: Full hostname for 'oaxaca.theory.phys.ucl.ac.uk' is 'oaxaca.theory.phys.ucl.ac.uk'
Aug  2 16:19:58 burroughs rpc.gssd[3390]: Full hostname for 'burroughs.theory.phys.ucl.ac.uk' is 'burroughs.theory.phys.ucl.ac.uk'
Aug  2 16:19:58 burroughs rpc.gssd[3390]: No key table entry found for BURROUGHS.THEORY.PHYS.UCL.AC.UK$@THEORY.PHYS.UCL.AC.UK while getting keyta
b entry for 'BURROUGHS.THEORY.PHYS.UCL.AC.UK$@THEORY.PHYS.UCL.AC.UK'
Aug  2 16:19:58 burroughs rpc.gssd[3390]: No key table entry found for root/burroughs.theory.phys.ucl.ac.uk.UCL.AC.UK while getting k
eytab entry for 'root/burroughs.theory.phys.ucl.ac.uk.UCL.AC.UK'
Aug  2 16:19:58 burroughs rpc.gssd[3390]: Success getting keytab entry for 'nfs/burroughs.theory.phys.ucl.ac.uk.UCL.AC.UK'
Aug  2 16:19:58 burroughs rpc.gssd[3390]: INFO: Credentials in CC 'FILE:/tmp/krb5cc_machine_THEORY.PHYS.UCL.AC.UK' are good until 1312383729
Aug  2 16:19:58 burroughs rpc.gssd[3390]: INFO: Credentials in CC 'FILE:/tmp/krb5cc_machine_THEORY.PHYS.UCL.AC.UK' are good until 1312383729
Aug  2 16:19:58 burroughs rpc.gssd[3390]: using FILE:/tmp/krb5cc_machine_THEORY.PHYS.UCL.AC.UK as credentials cache for machine creds
Aug  2 16:19:58 burroughs rpc.gssd[3390]: using environment variable to select krb5 ccache FILE:/tmp/krb5cc_machine_THEORY.PHYS.UCL.AC.UK
Aug  2 16:19:58 burroughs rpc.gssd[3390]: creating context using fsuid 0 (save_uid 0)
Aug  2 16:19:58 burroughs rpc.gssd[3390]: ERROR: GSS-API: error in gss_set_allowable_enctypes(): GSS_S_NO_CRED (No credentials were supplied, or 
the credentials were unavailable or inaccessible) - Unknown error
Aug  2 16:19:58 burroughs rpc.gssd[3390]: WARNING: Failed while limiting krb5 encryption types for user with uid 0
Aug  2 16:19:58 burroughs rpc.gssd[3390]: WARNING: Failed to create machine krb5 context with credentials cache FILE:/tmp/krb5cc_machine_THEORY.P
HYS.UCL.AC.UK for server oaxaca.theory.phys.ucl.ac.uk
Aug  2 16:19:58 burroughs rpc.gssd[3390]: WARNING: Failed to create machine krb5 context with any credentials cache for server oaxaca.theory.phys
.ucl.ac.uk
Aug  2 16:19:58 burroughs rpc.gssd[3390]: doing error downcall
Aug  2 16:19:58 burroughs rpc.gssd[3390]: dir_notify_handler: sig 37 si 0x7fff19c6dd70 data 0x7fff19c6dc40
Aug  2 16:19:58 burroughs rpc.gssd[3390]: dir_notify_handler: sig 37 si 0x7fff19c6e2b0 data 0x7fff19c6e180
Aug  2 16:19:58 burroughs rpc.gssd[3390]: dir_notify_handler: sig 37 si 0x7fff19c6e2b0 data 0x7fff19c6e180


Downgrading to nfs-utils-1.2.2-7 from rhel 6.0 and restarting rpcgssd I see success and the following in /var/log/messages:

Aug  2 16:26:45 burroughs rpc.gssd[4626]: handling gssd upcall (/var/lib/nfs/rpc_pipefs/nfs/clntc)
Aug  2 16:26:45 burroughs rpc.gssd[4626]: handle_gssd_upcall: 'mech=krb5 uid=0 enctypes=18,17,16,23,3,1,2 '
Aug  2 16:26:45 burroughs rpc.gssd[4626]: handling krb5 upcall (/var/lib/nfs/rpc_pipefs/nfs/clntc)
Aug  2 16:26:45 burroughs rpc.gssd[4626]: process_krb5_upcall: service is '<null>'
Aug  2 16:26:45 burroughs rpc.gssd[4626]: Full hostname for 'oaxaca.theory.phys.ucl.ac.uk' is 'oaxaca.theory.phys.ucl.ac.uk'
Aug  2 16:26:45 burroughs rpc.gssd[4626]: Full hostname for 'burroughs.theory.phys.ucl.ac.uk' is 'burroughs.theory.phys.ucl.ac.uk'
Aug  2 16:26:45 burroughs rpc.gssd[4626]: No key table entry found for root/burroughs.theory.phys.ucl.ac.uk.UCL.AC.UK while getting keytab entry for 'root/burroughs.theory.phys.ucl.ac.uk.UCL.AC.UK'
Aug  2 16:26:45 burroughs rpc.gssd[4626]: Success getting keytab entry for 'nfs/burroughs.theory.phys.ucl.ac.uk.UCL.AC.UK'
Aug  2 16:26:45 burroughs rpc.gssd[4626]: Successfully obtained machine credentials for principal 'nfs/burroughs.theory.phys.ucl.ac.uk.UCL.AC.UK' stored in ccache 'FILE:/tmp/krb5cc_machine_THEORY.PHYS.UCL.AC.UK'
Aug  2 16:26:45 burroughs rpc.gssd[4626]: INFO: Credentials in CC 'FILE:/tmp/krb5cc_machine_THEORY.PHYS.UCL.AC.UK' are good until 1312385205
Aug  2 16:26:45 burroughs rpc.gssd[4626]: using FILE:/tmp/krb5cc_machine_THEORY.PHYS.UCL.AC.UK as credentials cache for machine creds
Aug  2 16:26:45 burroughs rpc.gssd[4626]: using environment variable to select krb5 ccache FILE:/tmp/krb5cc_machine_THEORY.PHYS.UCL.AC.UK
Aug  2 16:26:45 burroughs rpc.gssd[4626]: creating context using fsuid 0 (save_uid 0)
Aug  2 16:26:45 burroughs rpc.gssd[4626]: creating tcp client for server oaxaca.theory.phys.ucl.ac.uk
Aug  2 16:26:45 burroughs rpc.gssd[4626]: DEBUG: port already set to 2049
Aug  2 16:26:45 burroughs rpc.gssd[4626]: creating context with server nfs.phys.ucl.ac.uk
Aug  2 16:26:45 burroughs rpc.gssd[4626]: DEBUG: serialize_krb5_ctx: lucid version!
Aug  2 16:26:45 burroughs rpc.gssd[4626]: prepare_krb5_rfc4121_buffer: protocol 1
Aug  2 16:26:45 burroughs rpc.gssd[4626]: prepare_krb5_rfc4121_buffer: serializing key with enctype 18 and size 32
Aug  2 16:26:45 burroughs rpc.gssd[4626]: doing downcall
Aug  2 16:26:45 burroughs kernel: Intel AES-NI instructions are not detected.
Aug  2 16:26:45 burroughs kernel: padlock: VIA PadLock not detected.
Aug  2 16:26:45 burroughs rpc.gssd[4626]: destroying client /var/lib/nfs/rpc_pipefs/nfs/clntd
Aug  2 16:26:45 burroughs rpc.gssd[4626]: handling gssd upcall (/var/lib/nfs/rpc_pipefs/nfs/clntc)
Aug  2 16:26:45 burroughs rpc.gssd[4626]: handle_gssd_upcall: 'mech=krb5 uid=10000 enctypes=18,17,16,23,3,1,2 '
Aug  2 16:26:45 burroughs rpc.gssd[4626]: handling krb5 upcall (/var/lib/nfs/rpc_pipefs/nfs/clntc)
Aug  2 16:26:45 burroughs rpc.gssd[4626]: process_krb5_upcall: service is '<null>'
Aug  2 16:26:45 burroughs rpc.gssd[4626]: getting credentials for client with uid 10000 for server oaxaca.theory.phys.ucl.ac.uk
Aug  2 16:26:45 burroughs rpc.gssd[4626]: CC file '/tmp/krb5cc_machine_THEORY.PHYS.UCL.AC.UK' being considered, with preferred realm 'THEORY.PHYS.UCL.AC.UK'
Aug  2 16:26:45 burroughs rpc.gssd[4626]: CC file '/tmp/krb5cc_machine_THEORY.PHYS.UCL.AC.UK' owned by 0, not 10000
Aug  2 16:26:45 burroughs rpc.gssd[4626]: CC file '/tmp/krb5cc_10000_VsfDdR' being considered, with preferred realm 'THEORY.PHYS.UCL.AC.UK'
Aug  2 16:26:45 burroughs rpc.gssd[4626]: CC file '/tmp/krb5cc_10000_VsfDdR'(jgu.UCL.AC.UK) passed all checks and has mtime of 1312298804
Aug  2 16:26:45 burroughs rpc.gssd[4626]: CC file '/tmp/krb5cc_0' being considered, with preferred realm 'THEORY.PHYS.UCL.AC.UK'
Aug  2 16:26:45 burroughs rpc.gssd[4626]: CC file '/tmp/krb5cc_0' owned by 0, not 10000
Aug  2 16:26:45 burroughs rpc.gssd[4626]: using FILE:/tmp/krb5cc_10000_VsfDdR as credentials cache for client with uid 10000 for server oaxaca.theory.phys.ucl.ac.uk
Aug  2 16:26:45 burroughs rpc.gssd[4626]: using environment variable to select krb5 ccache FILE:/tmp/krb5cc_10000_VsfDdR
Aug  2 16:26:45 burroughs rpc.gssd[4626]: creating context using fsuid 10000 (save_uid 0)
Aug  2 16:26:45 burroughs rpc.gssd[4626]: creating tcp client for server oaxaca.theory.phys.ucl.ac.uk
Aug  2 16:26:45 burroughs rpc.gssd[4626]: DEBUG: port already set to 2049
Aug  2 16:26:45 burroughs rpc.gssd[4626]: creating context with server nfs.phys.ucl.ac.uk
Aug  2 16:26:45 burroughs rpc.gssd[4626]: DEBUG: serialize_krb5_ctx: lucid version!
Aug  2 16:26:45 burroughs rpc.gssd[4626]: prepare_krb5_rfc4121_buffer: protocol 1
Aug  2 16:26:45 burroughs rpc.gssd[4626]: prepare_krb5_rfc4121_buffer: serializing key with enctype 18 and size 32
Aug  2 16:26:45 burroughs rpc.gssd[4626]: doing downcall
Aug  2 16:26:45 burroughs rpc.gssd[4626]: handling gssd upcall (/var/lib/nfs/rpc_pipefs/nfs/clntc)
Aug  2 16:26:45 burroughs rpc.gssd[4626]: handle_gssd_upcall: 'mech=krb5 uid=0 service=* enctypes=18,17,16,23,3,1,2 '
Aug  2 16:26:45 burroughs rpc.gssd[4626]: handling krb5 upcall (/var/lib/nfs/rpc_pipefs/nfs/clntc)
Aug  2 16:26:45 burroughs rpc.gssd[4626]: process_krb5_upcall: service is '*'
Aug  2 16:26:45 burroughs rpc.gssd[4626]: Full hostname for 'oaxaca.theory.phys.ucl.ac.uk' is 'oaxaca.theory.phys.ucl.ac.uk'
Aug  2 16:26:45 burroughs rpc.gssd[4626]: Full hostname for 'burroughs.theory.phys.ucl.ac.uk' is 'burroughs.theory.phys.ucl.ac.uk'
Aug  2 16:26:45 burroughs rpc.gssd[4626]: No key table entry found for root/burroughs.theory.phys.ucl.ac.uk.UCL.AC.UK while getting keytab entry for 'root/burroughs.theory.phys.ucl.ac.uk.UCL.AC.UK'
Aug  2 16:26:45 burroughs rpc.gssd[4626]: Success getting keytab entry for 'nfs/burroughs.theory.phys.ucl.ac.uk.UCL.AC.UK'
Aug  2 16:26:45 burroughs rpc.gssd[4626]: INFO: Credentials in CC 'FILE:/tmp/krb5cc_machine_THEORY.PHYS.UCL.AC.UK' are good until 1312385205
Aug  2 16:26:45 burroughs rpc.gssd[4626]: INFO: Credentials in CC 'FILE:/tmp/krb5cc_machine_THEORY.PHYS.UCL.AC.UK' are good until 1312385205
Aug  2 16:26:45 burroughs rpc.gssd[4626]: using FILE:/tmp/krb5cc_machine_THEORY.PHYS.UCL.AC.UK as credentials cache for machine creds
Aug  2 16:26:45 burroughs rpc.gssd[4626]: using environment variable to select krb5 ccache FILE:/tmp/krb5cc_machine_THEORY.PHYS.UCL.AC.UK
Aug  2 16:26:45 burroughs rpc.gssd[4626]: creating context using fsuid 0 (save_uid 0)
Aug  2 16:26:45 burroughs rpc.gssd[4626]: creating tcp client for server oaxaca.theory.phys.ucl.ac.uk
Aug  2 16:26:45 burroughs rpc.gssd[4626]: DEBUG: port already set to 2049
Aug  2 16:26:45 burroughs rpc.gssd[4626]: creating context with server nfs.phys.ucl.ac.uk
Aug  2 16:26:45 burroughs rpc.gssd[4626]: DEBUG: serialize_krb5_ctx: lucid version!
Aug  2 16:26:45 burroughs rpc.gssd[4626]: prepare_krb5_rfc4121_buffer: protocol 1
Aug  2 16:26:45 burroughs rpc.gssd[4626]: prepare_krb5_rfc4121_buffer: serializing key with enctype 18 and size 32
Aug  2 16:26:45 burroughs rpc.gssd[4626]: doing downcall

Comment 2 Jonathan Underwood 2011-08-02 17:48:28 UTC

The pertinent part in the failing case seems to be:

Aug  2 16:19:58 burroughs rpc.gssd[3390]: ERROR: GSS-API: error in
gss_set_allowable_enctypes(): GSS_S_NO_CRED (No credentials were supplied, or 
the credentials were unavailable or inaccessible) - Unknown error


Extra info - the server is running rhel 6.0

Comment 3 Tomasz Kepczynski 2011-08-02 19:16:50 UTC

This seems to be bug #719776 already reported on Fedora. I can confirm this issue on Scientific Linux where both client and server are on 6.1.

Comment 4 Jonathan Underwood 2011-08-02 19:51:46 UTC

It may well be related to bug #719776, but actually the error message is different. Also, I don't actually see anything in the server logs (despite passing -vvv to rpcsvcgssd), suggesting the client doesn't get as far as contacting the server. Do you see anything in the server log, Tomasz?

Comment 5 Tomasz Kepczynski 2011-08-02 20:18:43 UTC

Now when you mentioned it I see the difference. I have on the client:

Aug  2 20:59:04 vesemir rpc.gssd[2481]: ERROR: GSS-API: error in gss_set_allowable_enctypes(): GSS_S_NO_CRED (No credentials were supplied, or the credentials were unavailable or inaccessible) - Unknown error

and nothing related on the server (unless I screwed up ntp).

I also see one difference in relation to bug #719776:

vesemir:~> sudo klist -ekt
Keytab name: WRFILE:/etc/krb5.keytab
KVNO Timestamp         Principal
---- ----------------- --------------------------------------------------------
   2 03/19/11 10:34:22 host/vesemir.jot23.org (aes256-cts-hmac-sha1-96)
   2 03/19/11 10:34:22 host/vesemir.jot23.org (aes128-cts-hmac-sha1-96)
   2 03/19/11 10:34:23 host/vesemir.jot23.org (des3-cbc-sha1)
   2 03/19/11 10:34:23 host/vesemir.jot23.org (arcfour-hmac)
   2 03/19/11 10:34:23 host/vesemir.jot23.org (des-hmac-sha1)
   2 03/19/11 10:34:23 host/vesemir.jot23.org (des-cbc-md5)
   :
   2 04/22/11 23:21:04 nfs/vesemir.jot23.org (aes256-cts-hmac-sha1-96)
   2 04/22/11 23:21:04 nfs/vesemir.jot23.org (arcfour-hmac)
   2 04/22/11 23:21:05 nfs/vesemir.jot23.org (aes128-cts-hmac-sha1-96)
   2 04/22/11 23:21:05 nfs/vesemir.jot23.org (des3-cbc-sha1)
   2 04/22/11 23:21:05 nfs/vesemir.jot23.org (des-hmac-sha1)
   2 04/22/11 23:21:05 nfs/vesemir.jot23.org (des-cbc-md5)

I have des encryption types...

Everything broke when I upgraded both client and server to SL6.1, I cannot say which part is responsible.

Comment 6 Jonathan Underwood 2011-08-03 14:38:11 UTC

I actually wonder if this is caused by BZ #722616 as I also see that bug on the same system.

Comment 7 Tomasz Kepczynski 2011-08-03 17:28:03 UTC

I still have one SL 6.0 client left with nfs-utils-1.2.2-7.el6.x86_64. I've tried to mount home with sec=krb5p. I haven't seen a thing in /var/log/messages but on the server I see the following three entries:

Aug  3 19:19:10 triss rpc.svcgssd[5888]: ERROR: GSS-API: error in gss_export_lucid_sec_context(): GSS_S_NO_CONTEXT (No context has been established) - (0xbf9c1e08)
Aug  3 19:19:10 triss rpc.svcgssd[5888]: ERROR: failed serializing krb5 context for kernel
Aug  3 19:19:10 triss rpc.svcgssd[5888]: WARNING: handle_nullreq: serialize_context_for_kernel failed

Comment 8 Austin Foxley 2011-08-04 00:04:41 UTC

I believe it is related to the server bug #720479 with the same version. Looks like if you rebuild the nfs-utils-1.2.3 rpm from source, some libraries get linked in the wrong order.

Comment 9 Steve Dickson 2011-08-16 11:48:37 UTC

I can confirm, the fix for bug #720479, reordering the way libgssglue
is linked in does eliminate the GSS_S_NO_CONTEXT error seen in
Comment 7

*** This bug has been marked as a duplicate of bug 720479 ***

Note You need to log in before you can comment on or make changes to this bug.