Bug 1645083

Summary: rpc.gssd crashes when gssproxy is used and the RPCSEC_GSS library debug is enabled
Product: Red Hat Enterprise Linux 7 Reporter: Pierguido Lambri <plambri>
Component: nfs-utilsAssignee: Steve Dickson <steved>
Status: CLOSED ERRATA QA Contact: Yongcheng Yang <yoyang>
Severity: medium Docs Contact:
Priority: medium    
Version: 7.6CC: akaiser, amessina, cobrown, dwysocha, jshivers, jwedgeco, kolga, rharwood, riehecky, smayhew, steved, swhiteho, xzhou, yoyang
Target Milestone: rcKeywords: Patch, Reproducer
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: nfs-utils-1.3.0-0.67.el7 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2020-09-29 20:29:55 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Pierguido Lambri 2018-11-01 11:49:40 UTC 
Description of problem:
When using rpc.gssd in combination with gssproxy, rpc.gssd may misbehave 
and crash.

Version-Release number of selected component (if applicable):
nfs-utils-1.3.0-0.61.el7.x86_64
kernel-3.10.0-957.el7.x86_64

How reproducible:
Always in this specific configuration.

Steps to Reproduce:

1. Export the NFS client/server keytabs from a AD domain controller
2. Set up a NFS client and a NFS server with the right keytabs 
3. Export from the NFS server a krb5 share
4. Try to mount on the NFS client the share

Actual results:
mount.nfs: an incorrect mount option was specified

Expected results:
It should work.

Additional info:
Removing gssproxy from the equation makes rpc.gssd to work, but from the debug logs it seems gssproxy just handle the data to rpc.gssd which crashes.
Note the same issue happens on RHEL 7.5 too (I didn't test older versions).
Comment 2 Pierguido Lambri 2018-11-01 11:51:08 UTC 
Here are the logs after gssproxy has done the proxy work and the rpc.gssd crash:

...
Nov  1 11:38:50 rhel7-test1 gssproxy: [CID 11][2018/11/01 11:38:50]: Credentials allowed by configuration
Nov  1 11:38:50 rhel7-test1 gssproxy: GSSX_RES_INIT_SEC_CONTEXT( status: { 0 { 1 2 840 113554 1 2 2 } 0 "" "" [  ] } context_handle: { [ 00092affffff8648ffffff86fffffff71212225effffffa180001000100010000001320000000000000000000110008000105bffffffdaffffffe5ffffffc85bffffffdaffffffe5ffffffc85bffffffdb72685bffffffe4204840ffffffa100000061fffffff8effffffbe000030ffffffaa781ffffff97effffffa73700092affffff8648ffffff86fffffff712122ffffff97effffffa737ffffff97effffffa71000236e66732f7268656c372d74657374312e77696e2e6c6f63616c4057494e2e4c4f43414cffffff97effffffa71ffffff97effffffa71000286e66732f7268656c372d6e66732d7365727665722e77696e2e6c6f63616c4057494e2e4c4f43414cffffff97effffffa71ffffff97effffffa73000170001019731a1071ffffffeb4affffffb9114e2bfffffff72839ffffffcf6affffff97effffffa73ffffff97effffffa73000170001019731a1071ffffffeb4affffffb9114e2bfffffff72839ffffffcf6affffff97effffffa73ffffff97effffffa73000170001019731a1071ffffffeb4affffffb9114e2bfffffff72839ffffffcf6affffff97effffffa73ffffff97effffffa73800000000ffffffffffffffffffffffffffffffff0000178ffffffaa3000000000000000000000ffffff97effffffa738ffffff97effffffa724000000000007000120001100010000170003000100020012c00070000000800010000100000054ffffff97effffffa725fffffffffffffffffffffffffffffffe00000001ffffff97effffffa725ffffffaaffffffca60120001000e2f6574632f6b7262352e636f6e66ffffffaaffffffca6012ffffff97effffffa724ffffff97effffffa729000430ffffffaa78161fffffff8effffffbe00ffffff803000800000effffff82ffffff88ffffff97effffffa730001700010ffffffcb1d294922ffffff9affffffe9ffffff9cffffffdeffffffa911ffffffc17fffffffb8ffffff99ffffffbfffffff97effffffa730effffff82ffffff89ffffff97effffffa730001200020ffffffd0ffffffdbfffffff8ffffff9effffff89ffffffb64dfffffff7ffffff83ffffffbe64314ffffffad626dffffff9affffff88ffffffacfffffff3ffffffbe3effffffd4ffffffe0ffffffb7ffffff9471ffffff9213ffffffc0174affffff97effffffa730effffff82ffffff8affffff97effffffa730001200020ffffffd0ffffffdbfffffff8ffffff9effffff89ffffffb64dfffffff7ffffff83ffffffbe64314ffffffad626dffffff9affffff88ffffffacfffffff3ffffffbe3effffffd4ffffffe0ffffffb7ffffff9471ffffff9213ffffffc0174affffff97effffffa73ffffff97effffffa7e5bffffffdaffffffe5ffffffc807716661fffffff8effffffbeffffff97effffffa73000170001019731a1071ffffffeb4affffffb9114e2bfffffff72839ffffffcf6affffff97effffffa730001ffffff97effffffa7a00010001c301a3018ffffffa04220ffffff81ffffffa1104e30c2112211121102117ffffff97effffffa7affffff97effffffa7effffff97effffffa7290001ffffffffffffffffffffffff76ffffff97effffffa730001200020ffffffd0ffffffdbfffffff8ffffff9effffff89ffffffb64dfffffff7ffffff83ffffffbe64314ffffffad626dffffff9affffff88ffffffacfffffff3ffffffbe3effffffd4ffffffe0ffffffb7ffffff9471ffffff9213ffffffc0174affffff97effffffa73000100000000025effffffa18 ] [  ] 0 { 1 2 840 113554 1 2 2 } { "nfs/rhel7-test1.win.local" { 1 2 840 113554 1 2 2 1 } [ 410b692affffff8648ffffff86fffffff712122000236e66732f7268656c372d74657374312e77696e2e6c6f63616c4057494e2e4c4f43414c ] [ 420b692affffff8648ffffff86fffffff712122000236e66732f7268656c372d74657374312e77696e2e6c6f63616c4057494e2e4c4f43414c0000 ] [ ] } { "nfs/rhel7-nfs-server.win.local" { 1 2 840 113554 1 2 2 1 } [ 410b692affffff8648ffffff86fffffff712122000286e66732f7268656c372d6e66732d7365727665722e77696e2e6c6f63616c4057494e2e4c4f43414c ] [ 420b692affffff8648ffffff86fffffff712122000286e66732f7268656c372d6e66732d7365727665722e77696e2e6c6f63616c4057494e2e4c4f43414c0000 ] [ ] } 36000 306 1 1 } output_token: <Null> )
Nov  1 11:38:50 rhel7-test1 gssproxy: [CID 11][2018/11/01 11:38:50]: [status] Returned buffer 8 (GSSX_INIT_SEC_CONTEXT) from [0x558b7eda04d0 (1912)]: [0x7f2950051660 (1368)]
Nov  1 11:38:50 rhel7-test1 gssproxy: [CID 11][2018/11/01 11:38:50]: [status] Handling query output: 0x7f2950051660 (1368)
Nov  1 11:38:50 rhel7-test1 rpc.gssd[2983]: authgss_create_default: freeing name 0x7f0d50000950
Nov  1 11:38:50 rhel7-test1 gssproxy: [2018/11/01 11:38:50]: [status] Handling query reply: 0x7f2950051660 (1368)
Nov  1 11:38:50 rhel7-test1 gssproxy: [2018/11/01 11:38:50]: [status] Sending data: 0x7f2950051660 (1368)
Nov  1 11:38:50 rhel7-test1 gssproxy: [2018/11/01 11:38:50]: [status] Sending data [0x7f2950051660 (1368)]: successful write of 1368
Nov  1 11:38:50 rhel7-test1 rpc.gssd[2983]: in authgss_get_private_data()
Nov  1 11:38:50 rhel7-test1 rpc.gssd[2983]: doing downcall: lifetime_rec=36000 acceptor=nfs.local
Nov  1 11:38:50 rhel7-test1 rpc.gssd[2983]: in authgss_free_private_data()
Nov  1 11:38:50 rhel7-test1 rpc.gssd[2983]: in authgss_destroy()
Nov  1 11:38:50 rhel7-test1 rpc.gssd[2983]: in authgss_destroy_context()
Nov  1 11:38:50 rhel7-test1 rpc.gssd[2983]: authgss_destroy: freeing name 0x7f0d50004840
Nov  1 11:38:50 rhel7-test1 rpc.gssd[2983]: ERROR: event_dispatch() returned!
Nov  1 11:38:50 rhel7-test1 systemd: rpc-gssd.service: main process exited, code=exited, status=1/FAILURE
Nov  1 11:38:50 rhel7-test1 systemd: Unit rpc-gssd.service entered failed state.
Nov  1 11:38:50 rhel7-test1 systemd: rpc-gssd.service failed.
...
Comment 23 Yongcheng Yang 2020-02-25 02:46:13 UTC 
*** Bug 1806734 has been marked as a duplicate of this bug. ***
Comment 27 Yongcheng Yang 2020-04-27 05:24:18 UTC 
Verified in nfs-utils-1.3.0-0.67.el7

https://beaker.engineering.redhat.com/recipes/8181348#task109513584
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
[12:13:52 root@ ~~]# cat /etc/nfs.conf
[gssd]
 use-gss-proxy=yes
 verbosity=3
 rpc-verbosity=3   <<<
[12:13:52 root@ ~~]# service gssproxy restart
Redirecting to /bin/systemctl restart gssproxy.service
[12:13:52 root@ ~~]# service_rpcgssd restart
Redirecting to /bin/systemctl restart rpc-gssd.service
[12:13:52 root@ ~~]# service_rpcgssd status
Redirecting to /bin/systemctl status rpc-gssd.service
* rpc-gssd.service - RPC security service for NFS client and server
   Loaded: loaded (/usr/lib/systemd/system/rpc-gssd.service; static; vendor preset: disabled)
   Active: active (running) since Sun 2020-04-26 12:13:52 EDT; 43ms ago
  Process: 12558 ExecStart=/usr/sbin/rpc.gssd $GSSDARGS (code=exited, status=0/SUCCESS)
 Main PID: 12559 (rpc.gssd)
   CGroup: /system.slice/rpc-gssd.service
           `-12559 /usr/sbin/rpc.gssd

Apr 26 12:13:52 kvm-06-guest26.hv2.lab.eng.bos.redhat.com systemd[1]: Starting RPC security service for NFS client and server...
Apr 26 12:13:52 kvm-06-guest26.hv2.lab.eng.bos.redhat.com rpc.gssd[12558]: libtirpc: debug level 3
Apr 26 12:13:52 kvm-06-guest26.hv2.lab.eng.bos.redhat.com rpc.gssd[12559]: doing a full rescan
Apr 26 12:13:52 kvm-06-guest26.hv2.lab.eng.bos.redhat.com systemd[1]: Started RPC security service for NFS client and server.
[12:13:52 root@ ~~]# ps axf | grep [r]pc.gssd
12559 ?        Ss     0:00 /usr/sbin/rpc.gssd
Comment 29 errata-xmlrpc 2020-09-29 20:29:55 UTC 
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (nfs-utils bug fix and enhancement update), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2020:4002