rpc.svcgssd problem after updating client 1.2.2->1.2.3

rpc.svcgssd problem after updating client 1.2.2->1.2.3

[Vladimir Elisseev]

Hello,

I've got a problem after updating NFS client. I've been trying to find
possible solution without a success for a while, so I'd appreciate any
help. All the info is below. Client has kernel 2.6.37 and server 2.6.36.

Regards,
Vladimir.

On the server side the error is "rpc.svcgssd[15159]: qword_eol: fflush
failed: errno 22 (Invalid argument)", the full track is below:
Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: leaving poll
Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: handling null request
Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: sname = host/x.x.x@X.X
Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids: calling
umich_ldap->princ_to_ids
Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: ldap_init_and_bind: version
mismatch between API information and protocol version. Setting protocol
version to 3
Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids:
umich_ldap->princ_to_ids returned -2
Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids: calling
nsswitch->princ_to_ids
Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nss_getpwnam: name
'host/x.x.x@X.X' domain '(null)': resulting localname
'host/user.net.home'
Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids:
nsswitch->princ_to_ids returned -2
Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids: final
return value is -2
Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: DEBUG: serialize_krb5_ctx:
lucid version!
Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: prepare_krb5_rfc4121_buffer:
protocol 1
Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: prepare_krb5_rfc4121_buffer:
serializing key with enctype 18 and size 32
Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: doing downcall
Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: mech: krb5, hndl len: 4, ctx
len 52, timeout: 1300464362 (86399 from now), clnt: host@x.x.x, uid: -1,
gid: -1, num aux grps: 0:
Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: qword_eol: fflush failed: errno
22 (Invalid argument)
Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: WARNING: error writing to
downcall channel /proc/net/rpc/auth.rpcsec.context/channel: Invalid
argument
Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: sending null reply
Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: writing message: \x
\x6082025106092a864886f71201020201006e8202403082023ca003020105a10302010ea20703050020000000a38201486182014430820140a003020105a10a1b084e45542e484f4d45a21e301ca003020103a11530131b036e66731b0c6e66732e6e65742e686f6d65a382010b30820107a003020112a103020103a281fa0481f76d51de4ee749be6f5662e84fd91220874cd512114a52a7dbb0d1fb96da4768ec9d9f967a9664cc3a27626e0383a6a2e6930123efd709525a41420a68fdaa8fafabfab642f00c4e7d6dc4f075d900adf92f339d02b8ad1a162efeefa7501417280c553a430056634f4771a9bfa86c80eb758e7d530bff6dba5a112ca6b2412123e496a10ef93ac5af820b8751ec53db527acc059fcaee551edab8adc61f1dbc61ed9d16b65157974bd572d25ce62fd8c2e9d30650ef8cd35b12e315535cc1e53895bbd0a9589e02e2de1e62ca61e50e99f2b9f0456157bd3b3d739c6b6899b62f681f91e6072033e62e665ade4c366a1369315f19ca2e7da481da3081d7a003020112a281cf0481cc224de9a1f61431a8aee2b5a4f9fb6260230a0220c87c32030c528c80756b779eea25b272164e1c5e29b4d5be07557039cb7a9e230a5a8572dbe5bec750b952d57022d61ce29643f1110fece4e3c07ba027461e3e865f30a5ed29068cbec2e7a8d1dd18f66!
 50e6f2a565b7d779220c9c5c40c504533de623c63e3f229749f34e4d64cfc050083c09b3913371d0203994d3893a6640b6d9e1a5c43949f0b6567b755c99c4876f6987e7c3886d2eddd5cca1775ae4b0cde83910ddd786706c34fdbc18eca86206d42c05fd4fda4 1300378023 0 0 \x2d000000 \x60819906092a864886f71201020202006f8189308186a003020105a10302010fa27a3078a003020112a271046f5b995dfc1da7fffbad590382fac5637845400ac2b3d3943196e2c4ab8d55edfccfaf99b27d5e06ca56df734d817378c16a4b0c0fee21ecffd1be76b0cdffb8715e0cfe8659e3344407312e18194df2acd1795f8285f6f60ac31658d6bc678750f0fa0bb9e8d41ea2846832f8c7bc91
Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: finished handling null request
Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: entering poll

On the client side mount ends with "access denied" error, the full log
is below:
Mar 17 17:09:06 user rpc.gssd[32238]: handling gssd upcall
(/var/lib/nfs/rpc_pipefs/nfs/clnt37) 
Mar 17 17:09:06 user rpc.gssd[32238]: handle_gssd_upcall: 'mech=krb5
uid=0 enctypes=18,17,16,23,3,1,2 ' 
Mar 17 17:09:06 user rpc.gssd[32238]: handling krb5 upcall
(/var/lib/nfs/rpc_pipefs/nfs/clnt37) 
Mar 17 17:09:06 user rpc.gssd[32238]: process_krb5_upcall: service is
'<null>' 
Mar 17 17:09:06 user rpc.gssd[32238]: Full hostname for 'nfs.x.x' is
'nfs.x.x' 
Mar 17 17:09:06 user rpc.gssd[32238]: Full hostname for 'user.x.x' is
'user.x.x' 
Mar 17 17:09:06 user rpc.gssd[32238]: No key table entry found for
root/user.x.x@X.X while getting keytab entry for 'root/user.x.x@X.X' 
Mar 17 17:09:06 user rpc.gssd[32238]: No key table entry found for
nfs/user.x.x@X.X while getting keytab entry for 'nfs/user.x.x@X.X' 
Mar 17 17:09:06 user rpc.gssd[32238]: Success getting keytab entry for
'host/user.x.x@X.X' 
Mar 17 17:09:06 user rpc.gssd[32238]: Successfully obtained machine
credentials for principal 'host/user.x.x@X.X' stored in ccache
'FILE:/tmp/krb5cc_machine_x.x'    
Mar 17 17:09:06 user rpc.gssd[32238]: INFO: Credentials in CC
'FILE:/tmp/krb5cc_machine_x.x' are good until 1300464546 
Mar 17 17:09:06 user rpc.gssd[32238]: using FILE:/tmp/krb5cc_machine_x.x
as credentials cache for machine creds 
Mar 17 17:09:06 user rpc.gssd[32238]: using environment variable to
select krb5 ccache FILE:/tmp/krb5cc_machine_x.x 
Mar 17 17:09:06 user rpc.gssd[32238]: creating context using fsuid 0
(save_uid 0) 
Mar 17 17:09:06 user rpc.gssd[32238]: creating tcp client for server
nfs.x.x 
Mar 17 17:09:06 user rpc.gssd[32238]: DEBUG: port already set to 2049 
Mar 17 17:09:06 user rpc.gssd[32238]: creating context with server
nfs@nfs.x.x 
Mar 17 17:09:06 user rpc.gssd[32238]: WARNING: Failed to create krb5
context for user with uid 0 for server nfs.x.x 
Mar 17 17:09:06 user rpc.gssd[32238]: WARNING: Failed to create machine
krb5 context with credentials cache FILE:/tmp/krb5cc_machine_X.X for
server nfs.x.x 
Mar 17 17:09:06 user rpc.gssd[32238]: WARNING: Machine cache is
prematurely expired or corrupted trying to recreate cache for server
nfs.x.x 

Re: rpc.svcgssd problem after updating client 1.2.2->1.2.3

[Steve Dickson]

On 03/17/2011 02:48 PM, Vladimir Elisseev wrote:
> Hello,
> 
> I've got a problem after updating NFS client. I've been trying to find
> possible solution without a success for a while, so I'd appreciate any
> help. All the info is below. Client has kernel 2.6.37 and server 2.6.36.
> 
> Regards,
> Vladimir.
> 
> On the server side the error is "rpc.svcgssd[15159]: qword_eol: fflush
> failed: errno 22 (Invalid argument)", the full track is below:
I've seen this before but I believe it was in mountd. The fflush(3) call 
is failing with EINVAL on the upcall fd... I forget how it cleared its
self up..... 

steved.

> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: leaving poll
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: handling null request
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: sname = host/x.x.x@X.X
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids: calling
> umich_ldap->princ_to_ids
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: ldap_init_and_bind: version
> mismatch between API information and protocol version. Setting protocol
> version to 3
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids:
> umich_ldap->princ_to_ids returned -2
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids: calling
> nsswitch->princ_to_ids
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nss_getpwnam: name
> 'host/x.x.x@X.X' domain '(null)': resulting localname
> 'host/user.net.home'
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids:
> nsswitch->princ_to_ids returned -2
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids: final
> return value is -2
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: DEBUG: serialize_krb5_ctx:
> lucid version!
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: prepare_krb5_rfc4121_buffer:
> protocol 1
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: prepare_krb5_rfc4121_buffer:
> serializing key with enctype 18 and size 32
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: doing downcall
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: mech: krb5, hndl len: 4, ctx
> len 52, timeout: 1300464362 (86399 from now), clnt: host@x.x.x, uid: -1,
> gid: -1, num aux grps: 0:
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: qword_eol: fflush failed: errno
> 22 (Invalid argument)
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: WARNING: error writing to
> downcall channel /proc/net/rpc/auth.rpcsec.context/channel: Invalid
> argument
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: sending null reply
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: writing message: \x
> \x6082025106092a864886f71201020201006e8202403082023ca003020105a10302010ea20703050020000000a38201486182014430820140a003020105a10a1b084e45542e484f4d45a21e301ca003020103a11530131b036e66731b0c6e66732e6e65742e686f6d65a382010b30820107a003020112a103020103a281fa0481f76d51de4ee749be6f5662e84fd91220874cd512114a52a7dbb0d1fb96da4768ec9d9f967a9664cc3a27626e0383a6a2e6930123efd709525a41420a68fdaa8fafabfab642f00c4e7d6dc4f075d900adf92f339d02b8ad1a162efeefa7501417280c553a430056634f4771a9bfa86c80eb758e7d530bff6dba5a112ca6b2412123e496a10ef93ac5af820b8751ec53db527acc059fcaee551edab8adc61f1dbc61ed9d16b65157974bd572d25ce62fd8c2e9d30650ef8cd35b12e315535cc1e53895bbd0a9589e02e2de1e62ca61e50e99f2b9f0456157bd3b3d739c6b6899b62f681f91e6072033e62e665ade4c366a1369315f19ca2e7da481da3081d7a003020112a281cf0481cc224de9a1f61431a8aee2b5a4f9fb6260230a0220c87c32030c528c80756b779eea25b272164e1c5e29b4d5be07557039cb7a9e230a5a8572dbe5bec750b952d57022d61ce29643f1110fece4e3c07ba027461e3e865f30a5ed29068cbec2e7a8d1dd18f6
6!
>  50e6f2a565b7d779220c9c5c40c504533de623c63e3f229749f34e4d64cfc050083c09b3913371d0203994d3893a6640b6d9e1a5c43949f0b6567b755c99c4876f6987e7c3886d2eddd5cca1775ae4b0cde83910ddd786706c34fdbc18eca86206d42c05fd4fda4 1300378023 0 0 \x2d000000 \x60819906092a864886f71201020202006f8189308186a003020105a10302010fa27a3078a003020112a271046f5b995dfc1da7fffbad590382fac5637845400ac2b3d3943196e2c4ab8d55edfccfaf99b27d5e06ca56df734d817378c16a4b0c0fee21ecffd1be76b0cdffb8715e0cfe8659e3344407312e18194df2acd1795f8285f6f60ac31658d6bc678750f0fa0bb9e8d41ea2846832f8c7bc91
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: finished handling null request
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: entering poll
> 
> On the client side mount ends with "access denied" error, the full log
> is below:
> Mar 17 17:09:06 user rpc.gssd[32238]: handling gssd upcall
> (/var/lib/nfs/rpc_pipefs/nfs/clnt37) 
> Mar 17 17:09:06 user rpc.gssd[32238]: handle_gssd_upcall: 'mech=krb5
> uid=0 enctypes=18,17,16,23,3,1,2 ' 
> Mar 17 17:09:06 user rpc.gssd[32238]: handling krb5 upcall
> (/var/lib/nfs/rpc_pipefs/nfs/clnt37) 
> Mar 17 17:09:06 user rpc.gssd[32238]: process_krb5_upcall: service is
> '<null>' 
> Mar 17 17:09:06 user rpc.gssd[32238]: Full hostname for 'nfs.x.x' is
> 'nfs.x.x' 
> Mar 17 17:09:06 user rpc.gssd[32238]: Full hostname for 'user.x.x' is
> 'user.x.x' 
> Mar 17 17:09:06 user rpc.gssd[32238]: No key table entry found for
> root/user.x.x@X.X while getting keytab entry for 'root/user.x.x@X.X' 
> Mar 17 17:09:06 user rpc.gssd[32238]: No key table entry found for
> nfs/user.x.x@X.X while getting keytab entry for 'nfs/user.x.x@X.X' 
> Mar 17 17:09:06 user rpc.gssd[32238]: Success getting keytab entry for
> 'host/user.x.x@X.X' 
> Mar 17 17:09:06 user rpc.gssd[32238]: Successfully obtained machine
> credentials for principal 'host/user.x.x@X.X' stored in ccache
> 'FILE:/tmp/krb5cc_machine_x.x'    
> Mar 17 17:09:06 user rpc.gssd[32238]: INFO: Credentials in CC
> 'FILE:/tmp/krb5cc_machine_x.x' are good until 1300464546 
> Mar 17 17:09:06 user rpc.gssd[32238]: using FILE:/tmp/krb5cc_machine_x.x
> as credentials cache for machine creds 
> Mar 17 17:09:06 user rpc.gssd[32238]: using environment variable to
> select krb5 ccache FILE:/tmp/krb5cc_machine_x.x 
> Mar 17 17:09:06 user rpc.gssd[32238]: creating context using fsuid 0
> (save_uid 0) 
> Mar 17 17:09:06 user rpc.gssd[32238]: creating tcp client for server
> nfs.x.x 
> Mar 17 17:09:06 user rpc.gssd[32238]: DEBUG: port already set to 2049 
> Mar 17 17:09:06 user rpc.gssd[32238]: creating context with server
> nfs@nfs.x.x 
> Mar 17 17:09:06 user rpc.gssd[32238]: WARNING: Failed to create krb5
> context for user with uid 0 for server nfs.x.x 
> Mar 17 17:09:06 user rpc.gssd[32238]: WARNING: Failed to create machine
> krb5 context with credentials cache FILE:/tmp/krb5cc_machine_X.X for
> server nfs.x.x 
> Mar 17 17:09:06 user rpc.gssd[32238]: WARNING: Machine cache is
> prematurely expired or corrupted trying to recreate cache for server
> nfs.x.x 
> 
> 
> --
> 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

Re: rpc.svcgssd problem after updating client 1.2.2->1.2.3

[Vladimir Elisseev]

You're right, I saw about the same error with mountd, but the problem I
have is most likely related to the change: 

commit 76be349d5dd07f55797cb9920cc275667258f10f
Author: Kevin Coffman <kwc@citi.umich.edu>
Date:   Thu Apr 15 08:32:20 2010 -0400

    Try to use kernel function to determine supported Kerberos enctypes.

    This patch replaces a hard-coded list with a function to obtain
    the Kerberos encryption types that the kernel's rpcsec_gss code
    can support.  Defaults to old behavior if kernel does not supply
    information.

Regards,
Vladimir.

On Thu, 2011-03-17 at 16:57 -0400, Steve Dickson wrote:
> 
> On 03/17/2011 02:48 PM, Vladimir Elisseev wrote:
> > Hello,
> > 
> > I've got a problem after updating NFS client. I've been trying to find
> > possible solution without a success for a while, so I'd appreciate any
> > help. All the info is below. Client has kernel 2.6.37 and server 2.6.36.
> > 
> > Regards,
> > Vladimir.
> > 
> > On the server side the error is "rpc.svcgssd[15159]: qword_eol: fflush
> > failed: errno 22 (Invalid argument)", the full track is below:
> I've seen this before but I believe it was in mountd. The fflush(3) call 
> is failing with EINVAL on the upcall fd... I forget how it cleared its
> self up..... 
> 
> steved.
> 
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: leaving poll
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: handling null request
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: sname = host/x.x.x@X.X
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids: calling
> > umich_ldap->princ_to_ids
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: ldap_init_and_bind: version
> > mismatch between API information and protocol version. Setting protocol
> > version to 3
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids:
> > umich_ldap->princ_to_ids returned -2
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids: calling
> > nsswitch->princ_to_ids
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nss_getpwnam: name
> > 'host/x.x.x@X.X' domain '(null)': resulting localname
> > 'host/user.net.home'
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids:
> > nsswitch->princ_to_ids returned -2
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids: final
> > return value is -2
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: DEBUG: serialize_krb5_ctx:
> > lucid version!
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: prepare_krb5_rfc4121_buffer:
> > protocol 1
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: prepare_krb5_rfc4121_buffer:
> > serializing key with enctype 18 and size 32
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: doing downcall
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: mech: krb5, hndl len: 4, ctx
> > len 52, timeout: 1300464362 (86399 from now), clnt: host@x.x.x, uid: -1,
> > gid: -1, num aux grps: 0:
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: qword_eol: fflush failed: errno
> > 22 (Invalid argument)
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: WARNING: error writing to
> > downcall channel /proc/net/rpc/auth.rpcsec.context/channel: Invalid
> > argument
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: sending null reply
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: writing message: \x
> > \x6082025106092a864886f71201020201006e8202403082023ca003020105a10302010ea20703050020000000a38201486182014430820140a003020105a10a1b084e45542e484f4d45a21e301ca003020103a11530131b036e66731b0c6e66732e6e65742e686f6d65a382010b30820107a003020112a103020103a281fa0481f76d51de4ee749be6f5662e84fd91220874cd512114a52a7dbb0d1fb96da4768ec9d9f967a9664cc3a27626e0383a6a2e6930123efd709525a41420a68fdaa8fafabfab642f00c4e7d6dc4f075d900adf92f339d02b8ad1a162efeefa7501417280c553a430056634f4771a9bfa86c80eb758e7d530bff6dba5a112ca6b2412123e496a10ef93ac5af820b8751ec53db527acc059fcaee551edab8adc61f1dbc61ed9d16b65157974bd572d25ce62fd8c2e9d30650ef8cd35b12e315535cc1e53895bbd0a9589e02e2de1e62ca61e50e99f2b9f0456157bd3b3d739c6b6899b62f681f91e6072033e62e665ade4c366a1369315f19ca2e7da481da3081d7a003020112a281cf0481cc224de9a1f61431a8aee2b5a4f9fb6260230a0220c87c32030c528c80756b779eea25b272164e1c5e29b4d5be07557039cb7a9e230a5a8572dbe5bec750b952d57022d61ce29643f1110fece4e3c07ba027461e3e865f30a5ed29068cbec2e7a8d1dd18
 f6
> 6!
> >  50e6f2a565b7d779220c9c5c40c504533de623c63e3f229749f34e4d64cfc050083c09b3913371d0203994d3893a6640b6d9e1a5c43949f0b6567b755c99c4876f6987e7c3886d2eddd5cca1775ae4b0cde83910ddd786706c34fdbc18eca86206d42c05fd4fda4 1300378023 0 0 \x2d000000 \x60819906092a864886f71201020202006f8189308186a003020105a10302010fa27a3078a003020112a271046f5b995dfc1da7fffbad590382fac5637845400ac2b3d3943196e2c4ab8d55edfccfaf99b27d5e06ca56df734d817378c16a4b0c0fee21ecffd1be76b0cdffb8715e0cfe8659e3344407312e18194df2acd1795f8285f6f60ac31658d6bc678750f0fa0bb9e8d41ea2846832f8c7bc91
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: finished handling null request
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: entering poll
> > 
> > On the client side mount ends with "access denied" error, the full log
> > is below:
> > Mar 17 17:09:06 user rpc.gssd[32238]: handling gssd upcall
> > (/var/lib/nfs/rpc_pipefs/nfs/clnt37) 
> > Mar 17 17:09:06 user rpc.gssd[32238]: handle_gssd_upcall: 'mech=krb5
> > uid=0 enctypes=18,17,16,23,3,1,2 ' 
> > Mar 17 17:09:06 user rpc.gssd[32238]: handling krb5 upcall
> > (/var/lib/nfs/rpc_pipefs/nfs/clnt37) 
> > Mar 17 17:09:06 user rpc.gssd[32238]: process_krb5_upcall: service is
> > '<null>' 
> > Mar 17 17:09:06 user rpc.gssd[32238]: Full hostname for 'nfs.x.x' is
> > 'nfs.x.x' 
> > Mar 17 17:09:06 user rpc.gssd[32238]: Full hostname for 'user.x.x' is
> > 'user.x.x' 
> > Mar 17 17:09:06 user rpc.gssd[32238]: No key table entry found for
> > root/user.x.x@X.X while getting keytab entry for 'root/user.x.x@X.X' 
> > Mar 17 17:09:06 user rpc.gssd[32238]: No key table entry found for
> > nfs/user.x.x@X.X while getting keytab entry for 'nfs/user.x.x@X.X' 
> > Mar 17 17:09:06 user rpc.gssd[32238]: Success getting keytab entry for
> > 'host/user.x.x@X.X' 
> > Mar 17 17:09:06 user rpc.gssd[32238]: Successfully obtained machine
> > credentials for principal 'host/user.x.x@X.X' stored in ccache
> > 'FILE:/tmp/krb5cc_machine_x.x'    
> > Mar 17 17:09:06 user rpc.gssd[32238]: INFO: Credentials in CC
> > 'FILE:/tmp/krb5cc_machine_x.x' are good until 1300464546 
> > Mar 17 17:09:06 user rpc.gssd[32238]: using FILE:/tmp/krb5cc_machine_x.x
> > as credentials cache for machine creds 
> > Mar 17 17:09:06 user rpc.gssd[32238]: using environment variable to
> > select krb5 ccache FILE:/tmp/krb5cc_machine_x.x 
> > Mar 17 17:09:06 user rpc.gssd[32238]: creating context using fsuid 0
> > (save_uid 0) 
> > Mar 17 17:09:06 user rpc.gssd[32238]: creating tcp client for server
> > nfs.x.x 
> > Mar 17 17:09:06 user rpc.gssd[32238]: DEBUG: port already set to 2049 
> > Mar 17 17:09:06 user rpc.gssd[32238]: creating context with server
> > nfs@nfs.x.x 
> > Mar 17 17:09:06 user rpc.gssd[32238]: WARNING: Failed to create krb5
> > context for user with uid 0 for server nfs.x.x 
> > Mar 17 17:09:06 user rpc.gssd[32238]: WARNING: Failed to create machine
> > krb5 context with credentials cache FILE:/tmp/krb5cc_machine_X.X for
> > server nfs.x.x 
> > Mar 17 17:09:06 user rpc.gssd[32238]: WARNING: Machine cache is
> > prematurely expired or corrupted trying to recreate cache for server
> > nfs.x.x 
> > 
> > 
> > --
> > 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

Re: rpc.svcgssd problem after updating client 1.2.2->1.2.3

[Kevin Coffman]

On Thu, Mar 17, 2011 at 2:48 PM, Vladimir Elisseev <vovan@vovan.nl> wrote:
> Hello,
>
> I've got a problem after updating NFS client. I've been trying to find
> possible solution without a success for a while, so I'd appreciate any
> help. All the info is below. Client has kernel 2.6.37 and server 2.6.36.
>
> Regards,
> Vladimir.
>
> On the server side the error is "rpc.svcgssd[15159]: qword_eol: fflush
> failed: errno 22 (Invalid argument)", the full track is below:
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: leaving poll
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: handling null request
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: sname = host/x.x.x@X.X
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids: calling
> umich_ldap->princ_to_ids
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: ldap_init_and_bind: version
> mismatch between API information and protocol version. Setting protocol
> version to 3
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids:
> umich_ldap->princ_to_ids returned -2
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids: calling
> nsswitch->princ_to_ids
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nss_getpwnam: name
> 'host/x.x.x@X.X' domain '(null)': resulting localname
> 'host/user.net.home'
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids:
> nsswitch->princ_to_ids returned -2
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids: final
> return value is -2
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: DEBUG: serialize_krb5_ctx:
> lucid version!
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: prepare_krb5_rfc4121_buffer:
> protocol 1
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: prepare_krb5_rfc4121_buffer:
> serializing key with enctype 18 and size 32
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: doing downcall
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: mech: krb5, hndl len: 4, ctx
> len 52, timeout: 1300464362 (86399 from now), clnt: host@x.x.x, uid: -1,
> gid: -1, num aux grps: 0:
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: qword_eol: fflush failed: errno
> 22 (Invalid argument)
> Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: WARNING: error writing to
> downcall channel /proc/net/rpc/auth.rpcsec.context/channel: Invalid
> argument

I've seen this when the negotiated enctype is AES (18), and the kernel
does not have AES support.  However, 2.6.36 should have AES support.
Did the client update include a Kerberos version update as well?  (See
recently submitted patches regarding "acceptor subkey".)

The immediate work-around for the acceptor subkey problem is to set

  default_tgs_enctypes = des-cbc-crc

in the server's /etc/krb5.conf file.  Could you try this and see if it helps?

K.C.

Re: rpc.svcgssd problem after updating client 1.2.2->1.2.3

[Vladimir Elisseev]

Kevin,

I think the kernel configuration on server include AES encryption:
zcat /proc/config.gz| grep -i aes 
CONFIG_CRYPTO_AES=y
CONFIG_CRYPTO_AES_X86_64=y
# CONFIG_CRYPTO_AES_NI_INTEL is not set
IMO, this is sufficient. As for the kerberos version on the client it's
1.9 with patches: CVE-2010-4022, CVE-2011-0281,0282,0283,0284.
Changing server's krb5.conf with default_tgs_enctypes = des-cbc-crc
doesn't solve this problem.
As you suggested I'm going to check patches regarding "acceptor subkey".

Regards,
Vladimir.

On Thu, 2011-03-17 at 18:13 -0400, Kevin Coffman wrote:
> On Thu, Mar 17, 2011 at 2:48 PM, Vladimir Elisseev <vovan@vovan.nl> wrote:
> > Hello,
> >
> > I've got a problem after updating NFS client. I've been trying to find
> > possible solution without a success for a while, so I'd appreciate any
> > help. All the info is below. Client has kernel 2.6.37 and server 2.6.36.
> >
> > Regards,
> > Vladimir.
> >
> > On the server side the error is "rpc.svcgssd[15159]: qword_eol: fflush
> > failed: errno 22 (Invalid argument)", the full track is below:
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: leaving poll
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: handling null request
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: sname = host/x.x.x@X.X
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids: calling
> > umich_ldap->princ_to_ids
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: ldap_init_and_bind: version
> > mismatch between API information and protocol version. Setting protocol
> > version to 3
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids:
> > umich_ldap->princ_to_ids returned -2
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids: calling
> > nsswitch->princ_to_ids
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nss_getpwnam: name
> > 'host/x.x.x@X.X' domain '(null)': resulting localname
> > 'host/user.net.home'
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids:
> > nsswitch->princ_to_ids returned -2
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids: final
> > return value is -2
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: DEBUG: serialize_krb5_ctx:
> > lucid version!
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: prepare_krb5_rfc4121_buffer:
> > protocol 1
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: prepare_krb5_rfc4121_buffer:
> > serializing key with enctype 18 and size 32
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: doing downcall
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: mech: krb5, hndl len: 4, ctx
> > len 52, timeout: 1300464362 (86399 from now), clnt: host@x.x.x, uid: -1,
> > gid: -1, num aux grps: 0:
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: qword_eol: fflush failed: errno
> > 22 (Invalid argument)
> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: WARNING: error writing to
> > downcall channel /proc/net/rpc/auth.rpcsec.context/channel: Invalid
> > argument
> 
> I've seen this when the negotiated enctype is AES (18), and the kernel
> does not have AES support.  However, 2.6.36 should have AES support.
> Did the client update include a Kerberos version update as well?  (See
> recently submitted patches regarding "acceptor subkey".)
> 
> The immediate work-around for the acceptor subkey problem is to set
> 
>   default_tgs_enctypes = des-cbc-crc
> 
> in the server's /etc/krb5.conf file.  Could you try this and see if it helps?
> 
> K.C.
> --
> 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

Re: rpc.svcgssd problem after updating client 1.2.2->1.2.3

[Kevin Coffman]

Vladimir,
Having the raw crypto enabled in the kernel is only part of it.  The
RPC GSS support to make use of it went into 2.6.35, so your server's
kernel should have that.

Did the output from svcgssd change when you added the
default_tgs_enctypes?  Specifically, "prepare_krb5_rfc4121_buffer:
serializing key with enctype 18 and size 32" should have changed to a
different enctype and size.

If adding default_tgs_enctypes didn't help, the patches dealing with
"acceptor subkey" won't help.

Does the server continue to work for other clients?

K.C.

On Fri, Mar 18, 2011 at 1:43 AM, Vladimir Elisseev <vovan@vovan.nl> wrote:
> Kevin,
>
> I think the kernel configuration on server include AES encryption:
> zcat /proc/config.gz| grep -i aes
> CONFIG_CRYPTO_AES=y
> CONFIG_CRYPTO_AES_X86_64=y
> # CONFIG_CRYPTO_AES_NI_INTEL is not set
> IMO, this is sufficient. As for the kerberos version on the client it's
> 1.9 with patches: CVE-2010-4022, CVE-2011-0281,0282,0283,0284.
> Changing server's krb5.conf with default_tgs_enctypes = des-cbc-crc
> doesn't solve this problem.
> As you suggested I'm going to check patches regarding "acceptor subkey".
>
> Regards,
> Vladimir.
>
> On Thu, 2011-03-17 at 18:13 -0400, Kevin Coffman wrote:
>> On Thu, Mar 17, 2011 at 2:48 PM, Vladimir Elisseev <vovan@vovan.nl> wrote:
>> > Hello,
>> >
>> > I've got a problem after updating NFS client. I've been trying to find
>> > possible solution without a success for a while, so I'd appreciate any
>> > help. All the info is below. Client has kernel 2.6.37 and server 2.6.36.
>> >
>> > Regards,
>> > Vladimir.
>> >
>> > On the server side the error is "rpc.svcgssd[15159]: qword_eol: fflush
>> > failed: errno 22 (Invalid argument)", the full track is below:
>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: leaving poll
>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: handling null request
>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: sname = host/x.x.x@X.X
>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids: calling
>> > umich_ldap->princ_to_ids
>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: ldap_init_and_bind: version
>> > mismatch between API information and protocol version. Setting protocol
>> > version to 3
>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids:
>> > umich_ldap->princ_to_ids returned -2
>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids: calling
>> > nsswitch->princ_to_ids
>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nss_getpwnam: name
>> > 'host/x.x.x@X.X' domain '(null)': resulting localname
>> > 'host/user.net.home'
>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids:
>> > nsswitch->princ_to_ids returned -2
>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids: final
>> > return value is -2
>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: DEBUG: serialize_krb5_ctx:
>> > lucid version!
>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: prepare_krb5_rfc4121_buffer:
>> > protocol 1
>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: prepare_krb5_rfc4121_buffer:
>> > serializing key with enctype 18 and size 32
>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: doing downcall
>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: mech: krb5, hndl len: 4, ctx
>> > len 52, timeout: 1300464362 (86399 from now), clnt: host@x.x.x, uid: -1,
>> > gid: -1, num aux grps: 0:
>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: qword_eol: fflush failed: errno
>> > 22 (Invalid argument)
>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: WARNING: error writing to
>> > downcall channel /proc/net/rpc/auth.rpcsec.context/channel: Invalid
>> > argument
>>
>> I've seen this when the negotiated enctype is AES (18), and the kernel
>> does not have AES support.  However, 2.6.36 should have AES support.
>> Did the client update include a Kerberos version update as well?  (See
>> recently submitted patches regarding "acceptor subkey".)
>>
>> The immediate work-around for the acceptor subkey problem is to set
>>
>>   default_tgs_enctypes = des-cbc-crc
>>
>> in the server's /etc/krb5.conf file.  Could you try this and see if it helps?
>>
>> K.C.
>> --
>> 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
>
>

Re: rpc.svcgssd problem after updating client 1.2.2->1.2.3

[Vladimir Elisseev]

Kevin,

Sorry, I have to mention this initially: the server has nfs-utils
1.2.3, but clients have 1.2.2 (we've tested and upgraded servers
firstly without having any problems). As for the rest, see my comment
in-line below.

Regards,
Vladimir.

Quoting Kevin Coffman <kwc@citi.umich.edu>:

> Vladimir,
> Having the raw crypto enabled in the kernel is only part of it.  The
> RPC GSS support to make use of it went into 2.6.35, so your server's
> kernel should have that.
Thanks for clarifying this.

>
> Did the output from svcgssd change when you added the
> default_tgs_enctypes?  Specifically, "prepare_krb5_rfc4121_buffer:
> serializing key with enctype 18 and size 32" should have changed to a
> different enctype and size.
After changing krb5.conf I saw the same entry "repare_krb5_rfc4121_buffer:
serializing key with enctype 18 and size 32" in the log file. However,
I think I had to restart rpc.svcgssd (is this true?), but I didn't.
Unfortunately, changing default_tgs_enctypes for Kerberos will have
global effect and can be used only for testing purposes.

>
> If adding default_tgs_enctypes didn't help, the patches dealing with
> "acceptor subkey" won't help.
>
> Does the server continue to work for other clients?
As I mentioned at the beginning of this mail, clients with nfs-utils
1.2.2 work just fine and are able use des encryption:
klist -ce /tmp/krb5cc_machine_X.X
Ticket cache: FILE:/tmp/krb5cc_machine_X.X
Default principal: host/x.x.x@X.X

Valid starting     Expires            Service principal
03/18/11 06:40:36  03/19/11 06:40:36  krbtgt/X.X@X.X
          Etype (skey, tkt): aes256-cts-hmac-sha1-96, aes256-cts-hmac-sha1-96
03/18/11 06:40:37  03/19/11 06:40:36  nfs/nfs.x.x@X.X
          Etype (skey, tkt): des-cbc-crc, aes256-cts-hmac-sha1-96

> K.C.
>
> On Fri, Mar 18, 2011 at 1:43 AM, Vladimir Elisseev <vovan@vovan.nl> wrote:
>> Kevin,
>>
>> I think the kernel configuration on server include AES encryption:
>> zcat /proc/config.gz| grep -i aes
>> CONFIG_CRYPTO_AES=y
>> CONFIG_CRYPTO_AES_X86_64=y
>> # CONFIG_CRYPTO_AES_NI_INTEL is not set
>> IMO, this is sufficient. As for the kerberos version on the client it's
>> 1.9 with patches: CVE-2010-4022, CVE-2011-0281,0282,0283,0284.
>> Changing server's krb5.conf with default_tgs_enctypes = des-cbc-crc
>> doesn't solve this problem.
>> As you suggested I'm going to check patches regarding "acceptor subkey".
>>
>> Regards,
>> Vladimir.
>>
>> On Thu, 2011-03-17 at 18:13 -0400, Kevin Coffman wrote:
>>> On Thu, Mar 17, 2011 at 2:48 PM, Vladimir Elisseev <vovan@vovan.nl> wrote:
>>> > Hello,
>>> >
>>> > I've got a problem after updating NFS client. I've been trying to find
>>> > possible solution without a success for a while, so I'd appreciate any
>>> > help. All the info is below. Client has kernel 2.6.37 and server 2.6.36.
>>> >
>>> > Regards,
>>> > Vladimir.
>>> >
>>> > On the server side the error is "rpc.svcgssd[15159]: qword_eol: fflush
>>> > failed: errno 22 (Invalid argument)", the full track is below:
>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: leaving poll
>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: handling null request
>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: sname = host/x.x.x@X.X
>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids: calling
>>> > umich_ldap->princ_to_ids
>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: ldap_init_and_bind: version
>>> > mismatch between API information and protocol version. Setting protocol
>>> > version to 3
>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids:
>>> > umich_ldap->princ_to_ids returned -2
>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids: calling
>>> > nsswitch->princ_to_ids
>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nss_getpwnam: name
>>> > 'host/x.x.x@X.X' domain '(null)': resulting localname
>>> > 'host/user.net.home'
>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids:
>>> > nsswitch->princ_to_ids returned -2
>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids: final
>>> > return value is -2
>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: DEBUG: serialize_krb5_ctx:
>>> > lucid version!
>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: prepare_krb5_rfc4121_buffer:
>>> > protocol 1
>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: prepare_krb5_rfc4121_buffer:
>>> > serializing key with enctype 18 and size 32
>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: doing downcall
>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: mech: krb5, hndl len: 4, ctx
>>> > len 52, timeout: 1300464362 (86399 from now), clnt: host@x.x.x, uid: -1,
>>> > gid: -1, num aux grps: 0:
>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: qword_eol: fflush failed: errno
>>> > 22 (Invalid argument)
>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: WARNING: error writing to
>>> > downcall channel /proc/net/rpc/auth.rpcsec.context/channel: Invalid
>>> > argument
>>>
>>> I've seen this when the negotiated enctype is AES (18), and the kernel
>>> does not have AES support.  However, 2.6.36 should have AES support.
>>> Did the client update include a Kerberos version update as well?  (See
>>> recently submitted patches regarding "acceptor subkey".)
>>>
>>> The immediate work-around for the acceptor subkey problem is to set
>>>
>>>   default_tgs_enctypes = des-cbc-crc
>>>
>>> in the server's /etc/krb5.conf file.  Could you try this and see  
>>> if it helps?
>>>
>>> K.C.
>>> --
>>> 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
>

Re: rpc.svcgssd problem after updating client 1.2.2->1.2.3

[Kevin Coffman]

Re: the change to krb5.conf, yes I think you need to restart svcgssd.
And yes, it does have global effect (limiting all Kerberos connections
on the machine to DES), which is not optimal.

Offhand, I'm not aware of any changes to gssd or svcgssd between
nfs-utils 1.2.2 and 1.2.3 that would affect this.  Moving from
Kerberos 1.6 to something later would bring in the acceptor subkey
issue.  (I believe both sides need to have krb5-1.7 or later libraries
for the subkey to be used.)  But again, your server's kernel _should_
have RPC GSS support for AES.

The patch here, http://www.spinics.net/lists/linux-nfs/msg19999.html,
along with the Kerberos patch referenced there, should limit the
negotiation to DES.  (w/o the kernel patch, it will use a default list
of only DES enctypes).

However, it might be better to figure out why your kernel doesn't like
the AES key.  Looking back at the other issues like this, the error
returned when the kernel doesn't have RPC GSS support for AES was
"function not implemented", not "invalid argument".  Just as a sanity
check, you've verified that the rpcsec_gss_krb5 kernel module is
loaded?

K.C.

On Fri, Mar 18, 2011 at 9:52 AM, Vladimir Elisseev <vovan@vovan.nl> wrote:
> Kevin,
>
> Sorry, I have to mention this initially: the server has nfs-utils 1.2.3, but
> clients have 1.2.2 (we've tested and upgraded servers firstly without having
> any problems). As for the rest, see my comment in-line below.
>
> Regards,
> Vladimir.
>
> Quoting Kevin Coffman <kwc@citi.umich.edu>:
>
>> Vladimir,
>> Having the raw crypto enabled in the kernel is only part of it.  The
>> RPC GSS support to make use of it went into 2.6.35, so your server's
>> kernel should have that.
>
> Thanks for clarifying this.
>
>>
>> Did the output from svcgssd change when you added the
>> default_tgs_enctypes?  Specifically, "prepare_krb5_rfc4121_buffer:
>> serializing key with enctype 18 and size 32" should have changed to a
>> different enctype and size.
>
> After changing krb5.conf I saw the same entry "repare_krb5_rfc4121_buffer:
> serializing key with enctype 18 and size 32" in the log file. However, I
> think I had to restart rpc.svcgssd (is this true?), but I didn't.
> Unfortunately, changing default_tgs_enctypes for Kerberos will have global
> effect and can be used only for testing purposes.
>
>>
>> If adding default_tgs_enctypes didn't help, the patches dealing with
>> "acceptor subkey" won't help.
>>
>> Does the server continue to work for other clients?
>
> As I mentioned at the beginning of this mail, clients with nfs-utils 1.2.2
> work just fine and are able use des encryption:
> klist -ce /tmp/krb5cc_machine_X.X
> Ticket cache: FILE:/tmp/krb5cc_machine_X.X
> Default principal: host/x.x.x@X.X
>
> Valid starting     Expires            Service principal
> 03/18/11 06:40:36 03/19/11 06:40:36  krbtgt/X.X@X.X
>        Etype (skey, tkt): aes256-cts-hmac-sha1-96, aes256-cts-hmac-sha1-96
> 03/18/11 06:40:37  03/19/11 06:40:36  nfs/nfs.x.x@X.X
>        Etype (skey, tkt): des-cbc-crc, aes256-cts-hmac-sha1-96
>
>
>>
>> K.C.
>>
>> On Fri, Mar 18, 2011 at 1:43 AM, Vladimir Elisseev <vovan@vovan.nl> wrote:
>>>
>>> Kevin,
>>>
>>> I think the kernel configuration on server include AES encryption:
>>> zcat /proc/config.gz| grep -i aes
>>> CONFIG_CRYPTO_AES=y
>>> CONFIG_CRYPTO_AES_X86_64=y
>>> # CONFIG_CRYPTO_AES_NI_INTEL is not set
>>> IMO, this is sufficient. As for the kerberos version on the client it's
>>> 1.9 with patches: CVE-2010-4022, CVE-2011-0281,0282,0283,0284.
>>> Changing server's krb5.conf with default_tgs_enctypes = des-cbc-crc
>>> doesn't solve this problem.
>>> As you suggested I'm going to check patches regarding "acceptor subkey".
>>>
>>> Regards,
>>> Vladimir.
>>>
>>> On Thu, 2011-03-17 at 18:13 -0400, Kevin Coffman wrote:
>>>>
>>>> On Thu, Mar 17, 2011 at 2:48 PM, Vladimir Elisseev <vovan@vovan.nl>
>>>> wrote:
>>>> > Hello,
>>>> >
>>>> > I've got a problem after updating NFS client. I've been trying to find
>>>> > possible solution without a success for a while, so I'd appreciate any
>>>> > help. All the info is below. Client has kernel 2.6.37 and server
>>>> > 2.6.36.
>>>> >
>>>> > Regards,
>>>> > Vladimir.
>>>> >
>>>> > On the server side the error is "rpc.svcgssd[15159]: qword_eol: fflush
>>>> > failed: errno 22 (Invalid argument)", the full track is below:
>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: leaving poll
>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: handling null request
>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: sname = host/x.x.x@X.X
>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids:
>>>> > calling
>>>> > umich_ldap->princ_to_ids
>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: ldap_init_and_bind: version
>>>> > mismatch between API information and protocol version. Setting
>>>> > protocol
>>>> > version to 3
>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids:
>>>> > umich_ldap->princ_to_ids returned -2
>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids:
>>>> > calling
>>>> > nsswitch->princ_to_ids
>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nss_getpwnam: name
>>>> > 'host/x.x.x@X.X' domain '(null)': resulting localname
>>>> > 'host/user.net.home'
>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids:
>>>> > nsswitch->princ_to_ids returned -2
>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids: final
>>>> > return value is -2
>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: DEBUG: serialize_krb5_ctx:
>>>> > lucid version!
>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: prepare_krb5_rfc4121_buffer:
>>>> > protocol 1
>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: prepare_krb5_rfc4121_buffer:
>>>> > serializing key with enctype 18 and size 32
>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: doing downcall
>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: mech: krb5, hndl len: 4, ctx
>>>> > len 52, timeout: 1300464362 (86399 from now), clnt: host@x.x.x, uid:
>>>> > -1,
>>>> > gid: -1, num aux grps: 0:
>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: qword_eol: fflush failed:
>>>> > errno
>>>> > 22 (Invalid argument)
>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: WARNING: error writing to
>>>> > downcall channel /proc/net/rpc/auth.rpcsec.context/channel: Invalid
>>>> > argument
>>>>
>>>> I've seen this when the negotiated enctype is AES (18), and the kernel
>>>> does not have AES support.  However, 2.6.36 should have AES support.
>>>> Did the client update include a Kerberos version update as well?  (See
>>>> recently submitted patches regarding "acceptor subkey".)
>>>>
>>>> The immediate work-around for the acceptor subkey problem is to set
>>>>
>>>>   default_tgs_enctypes = des-cbc-crc
>>>>
>>>> in the server's /etc/krb5.conf file.  Could you try this and see if it
>>>> helps?
>>>>
>>>> K.C.
>>>> --
>>>> 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
>>>
>>>
>>
>
>
>
>
>

Re: rpc.svcgssd problem after updating client 1.2.2->1.2.3

[Vladimir Elisseev]

Kevin,

First of all, thank you for helping me with this issue.

Quoting Kevin Coffman <kwc@citi.umich.edu>:

> Re: the change to krb5.conf, yes I think you need to restart svcgssd.
> And yes, it does have global effect (limiting all Kerberos connections
> on the machine to DES), which is not optimal.

I'll try to reproduce this later then if needed.

>
> Offhand, I'm not aware of any changes to gssd or svcgssd between
> nfs-utils 1.2.2 and 1.2.3 that would affect this.  Moving from
> Kerberos 1.6 to something later would bring in the acceptor subkey
> issue.  (I believe both sides need to have krb5-1.7 or later libraries
> for the subkey to be used.)  But again, your server's kernel _should_
> have RPC GSS support for AES.

The version of mit-kerberos used on all machines is 1.9. As for the  
change in nfs-utils, the only one I've found related to kerberos is  
the one below:
commit 76be349d5dd07f55797cb9920cc275667258f10f
Author: Kevin Coffman <kwc@citi.umich.edu>
Date:   Thu Apr 15 08:32:20 2010 -0400

     Try to use kernel function to determine supported Kerberos enctypes.

     This patch replaces a hard-coded list with a function to obtain
     the Kerberos encryption types that the kernel's rpcsec_gss code
     can support.  Defaults to old behavior if kernel does not supply
     information.


>
> The patch here, http://www.spinics.net/lists/linux-nfs/msg19999.html,
> along with the Kerberos patch referenced there, should limit the
> negotiation to DES.  (w/o the kernel patch, it will use a default list
> of only DES enctypes).

After you mentioned this "acceptor subkey" patch, I took a look at  
both patches already.

>
> However, it might be better to figure out why your kernel doesn't like
> the AES key.  Looking back at the other issues like this, the error
> returned when the kernel doesn't have RPC GSS support for AES was
> "function not implemented", not "invalid argument".  Just as a sanity
> check, you've verified that the rpcsec_gss_krb5 kernel module is
> loaded?

I'm quite sure, that the rpcsec_gss_krb5 is in the kernel:
zcat /proc/config.gz| grep -i krb
CONFIG_RPCSEC_GSS_KRB5=y
However, as I recently understand, the nfs-utils package for servers  
has been compiled against linus-header-2.6.32. Could it be the root of  
my problem? If that so, simply recompiling nfs-utils will solw the  
issue ;-)

>
> K.C.

Regards,
Vladimir.

>
> On Fri, Mar 18, 2011 at 9:52 AM, Vladimir Elisseev <vovan@vovan.nl> wrote:
>> Kevin,
>>
>> Sorry, I have to mention this initially: the server has nfs-utils 1.2.3, but
>> clients have 1.2.2 (we've tested and upgraded servers firstly without having
>> any problems). As for the rest, see my comment in-line below.
>>
>> Regards,
>> Vladimir.
>>
>> Quoting Kevin Coffman <kwc@citi.umich.edu>:
>>
>>> Vladimir,
>>> Having the raw crypto enabled in the kernel is only part of it.  The
>>> RPC GSS support to make use of it went into 2.6.35, so your server's
>>> kernel should have that.
>>
>> Thanks for clarifying this.
>>
>>>
>>> Did the output from svcgssd change when you added the
>>> default_tgs_enctypes?  Specifically, "prepare_krb5_rfc4121_buffer:
>>> serializing key with enctype 18 and size 32" should have changed to a
>>> different enctype and size.
>>
>> After changing krb5.conf I saw the same entry "repare_krb5_rfc4121_buffer:
>> serializing key with enctype 18 and size 32" in the log file. However, I
>> think I had to restart rpc.svcgssd (is this true?), but I didn't.
>> Unfortunately, changing default_tgs_enctypes for Kerberos will have global
>> effect and can be used only for testing purposes.
>>
>>>
>>> If adding default_tgs_enctypes didn't help, the patches dealing with
>>> "acceptor subkey" won't help.
>>>
>>> Does the server continue to work for other clients?
>>
>> As I mentioned at the beginning of this mail, clients with nfs-utils 1.2.2
>> work just fine and are able use des encryption:
>> klist -ce /tmp/krb5cc_machine_X.X
>> Ticket cache: FILE:/tmp/krb5cc_machine_X.X
>> Default principal: host/x.x.x@X.X
>>
>> Valid starting     Expires            Service principal
>> 03/18/11 06:40:36 03/19/11 06:40:36  krbtgt/X.X@X.X
>>        Etype (skey, tkt): aes256-cts-hmac-sha1-96, aes256-cts-hmac-sha1-96
>> 03/18/11 06:40:37  03/19/11 06:40:36  nfs/nfs.x.x@X.X
>>        Etype (skey, tkt): des-cbc-crc, aes256-cts-hmac-sha1-96
>>
>>
>>>
>>> K.C.
>>>
>>> On Fri, Mar 18, 2011 at 1:43 AM, Vladimir Elisseev <vovan@vovan.nl> wrote:
>>>>
>>>> Kevin,
>>>>
>>>> I think the kernel configuration on server include AES encryption:
>>>> zcat /proc/config.gz| grep -i aes
>>>> CONFIG_CRYPTO_AES=y
>>>> CONFIG_CRYPTO_AES_X86_64=y
>>>> # CONFIG_CRYPTO_AES_NI_INTEL is not set
>>>> IMO, this is sufficient. As for the kerberos version on the client it's
>>>> 1.9 with patches: CVE-2010-4022, CVE-2011-0281,0282,0283,0284.
>>>> Changing server's krb5.conf with default_tgs_enctypes = des-cbc-crc
>>>> doesn't solve this problem.
>>>> As you suggested I'm going to check patches regarding "acceptor subkey".
>>>>
>>>> Regards,
>>>> Vladimir.
>>>>
>>>> On Thu, 2011-03-17 at 18:13 -0400, Kevin Coffman wrote:
>>>>>
>>>>> On Thu, Mar 17, 2011 at 2:48 PM, Vladimir Elisseev <vovan@vovan.nl>
>>>>> wrote:
>>>>> > Hello,
>>>>> >
>>>>> > I've got a problem after updating NFS client. I've been trying to find
>>>>> > possible solution without a success for a while, so I'd appreciate any
>>>>> > help. All the info is below. Client has kernel 2.6.37 and server
>>>>> > 2.6.36.
>>>>> >
>>>>> > Regards,
>>>>> > Vladimir.
>>>>> >
>>>>> > On the server side the error is "rpc.svcgssd[15159]: qword_eol: fflush
>>>>> > failed: errno 22 (Invalid argument)", the full track is below:
>>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: leaving poll
>>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: handling null request
>>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: sname = host/x.x.x@X.X
>>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids:
>>>>> > calling
>>>>> > umich_ldap->princ_to_ids
>>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: ldap_init_and_bind: version
>>>>> > mismatch between API information and protocol version. Setting
>>>>> > protocol
>>>>> > version to 3
>>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids:
>>>>> > umich_ldap->princ_to_ids returned -2
>>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids:
>>>>> > calling
>>>>> > nsswitch->princ_to_ids
>>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nss_getpwnam: name
>>>>> > 'host/x.x.x@X.X' domain '(null)': resulting localname
>>>>> > 'host/user.net.home'
>>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids:
>>>>> > nsswitch->princ_to_ids returned -2
>>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: nfs4_gss_princ_to_ids: final
>>>>> > return value is -2
>>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: DEBUG: serialize_krb5_ctx:
>>>>> > lucid version!
>>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: prepare_krb5_rfc4121_buffer:
>>>>> > protocol 1
>>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: prepare_krb5_rfc4121_buffer:
>>>>> > serializing key with enctype 18 and size 32
>>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: doing downcall
>>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: mech: krb5, hndl len: 4, ctx
>>>>> > len 52, timeout: 1300464362 (86399 from now), clnt: host@x.x.x, uid:
>>>>> > -1,
>>>>> > gid: -1, num aux grps: 0:
>>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: qword_eol: fflush failed:
>>>>> > errno
>>>>> > 22 (Invalid argument)
>>>>> > Mar 17 17:06:03 srv2 rpc.svcgssd[15159]: WARNING: error writing to
>>>>> > downcall channel /proc/net/rpc/auth.rpcsec.context/channel: Invalid
>>>>> > argument
>>>>>
>>>>> I've seen this when the negotiated enctype is AES (18), and the kernel
>>>>> does not have AES support.  However, 2.6.36 should have AES support.
>>>>> Did the client update include a Kerberos version update as well?  (See
>>>>> recently submitted patches regarding "acceptor subkey".)
>>>>>
>>>>> The immediate work-around for the acceptor subkey problem is to set
>>>>>
>>>>>   default_tgs_enctypes = des-cbc-crc
>>>>>
>>>>> in the server's /etc/krb5.conf file.  Could you try this and see if it
>>>>> helps?
>>>>>
>>>>> K.C.
>>>>> --
>>>>> 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
>

Re: rpc.svcgssd problem after updating client 1.2.2->1.2.3

[Kevin Coffman]

On Fri, Mar 18, 2011 at 11:48 AM, Vladimir Elisseev <vovan@vovan.nl> wrote:
> Kevin,
>
> First of all, thank you for helping me with this issue.
>
> Quoting Kevin Coffman <kwc@citi.umich.edu>:
>
>> Re: the change to krb5.conf, yes I think you need to restart svcgssd.
>> And yes, it does have global effect (limiting all Kerberos connections
>> on the machine to DES), which is not optimal.
>
> I'll try to reproduce this later then if needed.

Sounds good.

>> Offhand, I'm not aware of any changes to gssd or svcgssd between
>> nfs-utils 1.2.2 and 1.2.3 that would affect this.  Moving from
>> Kerberos 1.6 to something later would bring in the acceptor subkey
>> issue.  (I believe both sides need to have krb5-1.7 or later libraries
>> for the subkey to be used.)  But again, your server's kernel _should_
>> have RPC GSS support for AES.
>
> The version of mit-kerberos used on all machines is 1.9. As for the change
> in nfs-utils, the only one I've found related to kerberos is the one below:
> commit 76be349d5dd07f55797cb9920cc275667258f10f
> Author: Kevin Coffman <kwc@citi.umich.edu>
> Date:   Thu Apr 15 08:32:20 2010 -0400
>
>    Try to use kernel function to determine supported Kerberos enctypes.
>
>    This patch replaces a hard-coded list with a function to obtain
>    the Kerberos encryption types that the kernel's rpcsec_gss code
>    can support.  Defaults to old behavior if kernel does not supply
>    information.

Wow! I've totally lost track of what version of nfs-utils this stuff
went into.  That patch deals only with limiting the encryption types
from the client side.  We assumed at that time that limiting the
enctypes in the server's keytab was all that would be needed to limit
the negotiated enctypes on the server side.

Looking back at the Changelog, the other important patch is this:

commit 4c5ff6d48021731128c4fc13d51610645a6fcf5c
Author: Kevin Coffman <kwc@citi.umich.edu>
Date:   Mon Apr 12 17:13:25 2010 -0400

    Add support for non-DES encryption types.

    Sends a new format of context information to the kernel.
    (Requires kernel support to do anything useful.)

>> The patch here, http://www.spinics.net/lists/linux-nfs/msg19999.html,
>> along with the Kerberos patch referenced there, should limit the
>> negotiation to DES.  (w/o the kernel patch, it will use a default list
>> of only DES enctypes).
>
> After you mentioned this "acceptor subkey" patch, I took a look at both
> patches already.
>
>>
>> However, it might be better to figure out why your kernel doesn't like
>> the AES key.  Looking back at the other issues like this, the error
>> returned when the kernel doesn't have RPC GSS support for AES was
>> "function not implemented", not "invalid argument".  Just as a sanity
>> check, you've verified that the rpcsec_gss_krb5 kernel module is
>> loaded?
>
> I'm quite sure, that the rpcsec_gss_krb5 is in the kernel:
> zcat /proc/config.gz| grep -i krb
> CONFIG_RPCSEC_GSS_KRB5=y
> However, as I recently understand, the nfs-utils package for servers has
> been compiled against linus-header-2.6.32. Could it be the root of my
> problem? If that so, simply recompiling nfs-utils will solw the issue ;-)

That would be nice if it was the case.  I am really not sure whether
there are kernel header dependencies that could cause this.

K.C.

Re: rpc.svcgssd problem after updating client 1.2.2->1.2.3

[Vladimir Elisseev]

Kevin,

I have some updates. I recompiled nfs-utils and dependencies (libgssglue
keyutils librpcsecgss libtirpc) on the server and on the test client.
Nevertheless, while on the server side I see the same error:
rpc.svcgssd[8390]: qword_eol: fflush failed: errno 22 (Invalid argument)
on the client side rpc.gssd segfault(!):
kernel: rpc.gssd[2107] segfault at 4 ip 0000003ef9430805 sp 00007fff655cdd10 error 4 in libgssapi_krb5.so.2.2[3ef9400000+3e000]
Reverting back to nfs-utils 1.2.2 on the client and everything is fine.
Below are relevant log entries from KDC when using nfs-utils 1.2.2 and 1.2.3 on the client:

****** nfs-utils 1.2.2 *******
Mar 19 07:56:27 srv2 krb5kdc[7945]: AS_REQ (7 etypes {18 17 16 23 1 3 2}) 192.168.1.8: ISSUE: authtime 1300517787, etypes {rep=18 tkt=18 ses=18}, host/vbox.xxx.xxx@X.X for krbtgt/X.X@X.X 
Mar 19 07:56:28 srv2 krb5kdc[7945]: TGS_REQ (7 etypes {18 17 16 23 1 3 2}) 192.168.1.8: ISSUE: authtime 1300517787, etypes {rep=18 tkt=18 ses=18}, host/vbox.xxx.xxx@X.X for nfs/nfs.xxx.xxx@X.X 
Mar 19 07:56:28 srv2 krb5kdc[7945]: TGS_REQ (3 etypes {1 3 2}) 192.168.1.8: ISSUE: authtime 1300517787, etypes {rep=18 tkt=18 ses=1}, host/vbox.xxx.xxx@X.X for nfs/nfs.xxx.xxx@X.X 

****** nfs-utils 1.2.3 *******
Mar 19 08:22:22 srv2 krb5kdc[7945]: AS_REQ (7 etypes {18 17 16 23 1 3 2}) 192.168.1.2: ISSUE: authtime 1300519342, etypes {rep=18 tkt=18 ses=18}, host/x.x.x@X.X for krbtgt/X.X@X.X 
Mar 19 08:22:22 srv2 krb5kdc[7945]: TGS_REQ (7 etypes {18 17 16 23 1 3 2}) 192.168.1.2: ISSUE: authtime 1300519342, etypes {rep=18 tkt=18 ses=18}, host/x.x.x@X.X for nfs/nfs.x.x@X.X
then
rpc.svcgssd[8390]: qword_eol: fflush failed: errno 22 (Invalid argument) 
and segfault on the client side.

Regards,
Vladimir. 

On Fri, 2011-03-18 at 12:36 -0400, Kevin Coffman wrote:
> On Fri, Mar 18, 2011 at 11:48 AM, Vladimir Elisseev <vovan@vovan.nl> wrote:
> > Kevin,
> >
> > First of all, thank you for helping me with this issue.
> >
> > Quoting Kevin Coffman <kwc@citi.umich.edu>:
> >
> >> Re: the change to krb5.conf, yes I think you need to restart svcgssd.
> >> And yes, it does have global effect (limiting all Kerberos connections
> >> on the machine to DES), which is not optimal.
> >
> > I'll try to reproduce this later then if needed.
> 
> Sounds good.
> 
> >> Offhand, I'm not aware of any changes to gssd or svcgssd between
> >> nfs-utils 1.2.2 and 1.2.3 that would affect this.  Moving from
> >> Kerberos 1.6 to something later would bring in the acceptor subkey
> >> issue.  (I believe both sides need to have krb5-1.7 or later libraries
> >> for the subkey to be used.)  But again, your server's kernel _should_
> >> have RPC GSS support for AES.
> >
> > The version of mit-kerberos used on all machines is 1.9. As for the change
> > in nfs-utils, the only one I've found related to kerberos is the one below:
> > commit 76be349d5dd07f55797cb9920cc275667258f10f
> > Author: Kevin Coffman <kwc@citi.umich.edu>
> > Date:   Thu Apr 15 08:32:20 2010 -0400
> >
> >    Try to use kernel function to determine supported Kerberos enctypes.
> >
> >    This patch replaces a hard-coded list with a function to obtain
> >    the Kerberos encryption types that the kernel's rpcsec_gss code
> >    can support.  Defaults to old behavior if kernel does not supply
> >    information.
> 
> Wow! I've totally lost track of what version of nfs-utils this stuff
> went into.  That patch deals only with limiting the encryption types
> from the client side.  We assumed at that time that limiting the
> enctypes in the server's keytab was all that would be needed to limit
> the negotiated enctypes on the server side.
> 
> Looking back at the Changelog, the other important patch is this:
> 
> commit 4c5ff6d48021731128c4fc13d51610645a6fcf5c
> Author: Kevin Coffman <kwc@citi.umich.edu>
> Date:   Mon Apr 12 17:13:25 2010 -0400
> 
>     Add support for non-DES encryption types.
> 
>     Sends a new format of context information to the kernel.
>     (Requires kernel support to do anything useful.)
> 
> >> The patch here, http://www.spinics.net/lists/linux-nfs/msg19999.html,
> >> along with the Kerberos patch referenced there, should limit the
> >> negotiation to DES.  (w/o the kernel patch, it will use a default list
> >> of only DES enctypes).
> >
> > After you mentioned this "acceptor subkey" patch, I took a look at both
> > patches already.
> >
> >>
> >> However, it might be better to figure out why your kernel doesn't like
> >> the AES key.  Looking back at the other issues like this, the error
> >> returned when the kernel doesn't have RPC GSS support for AES was
> >> "function not implemented", not "invalid argument".  Just as a sanity
> >> check, you've verified that the rpcsec_gss_krb5 kernel module is
> >> loaded?
> >
> > I'm quite sure, that the rpcsec_gss_krb5 is in the kernel:
> > zcat /proc/config.gz| grep -i krb
> > CONFIG_RPCSEC_GSS_KRB5=y
> > However, as I recently understand, the nfs-utils package for servers has
> > been compiled against linus-header-2.6.32. Could it be the root of my
> > problem? If that so, simply recompiling nfs-utils will solw the issue ;-)
> 
> That would be nice if it was the case.  I am really not sure whether
> there are kernel header dependencies that could cause this.
> 
> K.C.
> --
> 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

Re: rpc.svcgssd problem after updating client 1.2.2->1.2.3

[Steve Dickson]

On 03/19/2011 03:56 AM, Vladimir Elisseev wrote:
> Kevin,
> 
> I have some updates. I recompiled nfs-utils and dependencies (libgssglue
> keyutils librpcsecgss libtirpc) on the server and on the test client.
> Nevertheless, while on the server side I see the same error:
> rpc.svcgssd[8390]: qword_eol: fflush failed: errno 22 (Invalid argument)
> on the client side rpc.gssd segfault(!):
> kernel: rpc.gssd[2107] segfault at 4 ip 0000003ef9430805 sp 00007fff655cdd10 error 4 in libgssapi_krb5.so.2.2[3ef9400000+3e000]
> Reverting back to nfs-utils 1.2.2 on the client and everything is fine.
> Below are relevant log entries from KDC when using nfs-utils 1.2.2 and 1.2.3 on the client:
> 
> ****** nfs-utils 1.2.2 *******
> Mar 19 07:56:27 srv2 krb5kdc[7945]: AS_REQ (7 etypes {18 17 16 23 1 3 2}) 192.168.1.8: ISSUE: authtime 1300517787, etypes {rep=18 tkt=18 ses=18}, host/vbox.xxx.xxx@X.X for krbtgt/X.X@X.X 
> Mar 19 07:56:28 srv2 krb5kdc[7945]: TGS_REQ (7 etypes {18 17 16 23 1 3 2}) 192.168.1.8: ISSUE: authtime 1300517787, etypes {rep=18 tkt=18 ses=18}, host/vbox.xxx.xxx@X.X for nfs/nfs.xxx.xxx@X.X 
> Mar 19 07:56:28 srv2 krb5kdc[7945]: TGS_REQ (3 etypes {1 3 2}) 192.168.1.8: ISSUE: authtime 1300517787, etypes {rep=18 tkt=18 ses=1}, host/vbox.xxx.xxx@X.X for nfs/nfs.xxx.xxx@X.X 
> 
> ****** nfs-utils 1.2.3 *******
> Mar 19 08:22:22 srv2 krb5kdc[7945]: AS_REQ (7 etypes {18 17 16 23 1 3 2}) 192.168.1.2: ISSUE: authtime 1300519342, etypes {rep=18 tkt=18 ses=18}, host/x.x.x@X.X for krbtgt/X.X@X.X 
> Mar 19 08:22:22 srv2 krb5kdc[7945]: TGS_REQ (7 etypes {18 17 16 23 1 3 2}) 192.168.1.2: ISSUE: authtime 1300519342, etypes {rep=18 tkt=18 ses=18}, host/x.x.x@X.X for nfs/nfs.x.x@X.X
> then
> rpc.svcgssd[8390]: qword_eol: fflush failed: errno 22 (Invalid argument) 
> and segfault on the client side.
Would it be possible to get a back trace from the core?

steved.

Re: rpc.svcgssd problem after updating client 1.2.2->1.2.3

[Vladimir Elisseev]

Steve,

The segfault on the client side is gone after client reboot. This
segfault occurs when nfs-utils has been updated and then I just restart
corresponding services (rpcbind, rpc.idmapd, rpc.gssd) without rebooting
the client. Now client simply exits with the lines below (as I described
initially in my first mail): 
mount.nfs: mount(2): Permission denied
mount.nfs: access denied by server while mounting ...

Regards,
Vladimir.

On Sat, 2011-03-19 at 22:19 -0400, Steve Dickson wrote:
> 
> On 03/19/2011 03:56 AM, Vladimir Elisseev wrote:
> > Kevin,
> > 
> > I have some updates. I recompiled nfs-utils and dependencies (libgssglue
> > keyutils librpcsecgss libtirpc) on the server and on the test client.
> > Nevertheless, while on the server side I see the same error:
> > rpc.svcgssd[8390]: qword_eol: fflush failed: errno 22 (Invalid argument)
> > on the client side rpc.gssd segfault(!):
> > kernel: rpc.gssd[2107] segfault at 4 ip 0000003ef9430805 sp 00007fff655cdd10 error 4 in libgssapi_krb5.so.2.2[3ef9400000+3e000]
> > Reverting back to nfs-utils 1.2.2 on the client and everything is fine.
> > Below are relevant log entries from KDC when using nfs-utils 1.2.2 and 1.2.3 on the client:
> > 
> > ****** nfs-utils 1.2.2 *******
> > Mar 19 07:56:27 srv2 krb5kdc[7945]: AS_REQ (7 etypes {18 17 16 23 1 3 2}) 192.168.1.8: ISSUE: authtime 1300517787, etypes {rep=18 tkt=18 ses=18}, host/vbox.xxx.xxx@X.X for krbtgt/X.X@X.X 
> > Mar 19 07:56:28 srv2 krb5kdc[7945]: TGS_REQ (7 etypes {18 17 16 23 1 3 2}) 192.168.1.8: ISSUE: authtime 1300517787, etypes {rep=18 tkt=18 ses=18}, host/vbox.xxx.xxx@X.X for nfs/nfs.xxx.xxx@X.X 
> > Mar 19 07:56:28 srv2 krb5kdc[7945]: TGS_REQ (3 etypes {1 3 2}) 192.168.1.8: ISSUE: authtime 1300517787, etypes {rep=18 tkt=18 ses=1}, host/vbox.xxx.xxx@X.X for nfs/nfs.xxx.xxx@X.X 
> > 
> > ****** nfs-utils 1.2.3 *******
> > Mar 19 08:22:22 srv2 krb5kdc[7945]: AS_REQ (7 etypes {18 17 16 23 1 3 2}) 192.168.1.2: ISSUE: authtime 1300519342, etypes {rep=18 tkt=18 ses=18}, host/x.x.x@X.X for krbtgt/X.X@X.X 
> > Mar 19 08:22:22 srv2 krb5kdc[7945]: TGS_REQ (7 etypes {18 17 16 23 1 3 2}) 192.168.1.2: ISSUE: authtime 1300519342, etypes {rep=18 tkt=18 ses=18}, host/x.x.x@X.X for nfs/nfs.x.x@X.X
> > then
> > rpc.svcgssd[8390]: qword_eol: fflush failed: errno 22 (Invalid argument) 
> > and segfault on the client side.
> Would it be possible to get a back trace from the core?
> 
> steved.

Re: rpc.svcgssd problem after updating client 1.2.2->1.2.3

[Steve Dickson]

On 03/21/2011 01:36 AM, Vladimir Elisseev wrote:
> Steve,
> 
> The segfault on the client side is gone after client reboot. This
> segfault occurs when nfs-utils has been updated and then I just restart
> corresponding services (rpcbind, rpc.idmapd, rpc.gssd) without rebooting
> the client. Now client simply exits with the lines below (as I described
> initially in my first mail): 
> mount.nfs: mount(2): Permission denied
> mount.nfs: access denied by server while mounting ...
Ok.. to find out where rpc.gssd is segfaulting do the following:

# debuginfo-install nfs-utils
(assuming Fedora)
# gdb /usr/sbin/rpc.gssd 
gdb> run -f -vvv 
(When the segfault happens)
gdb> bt 
(which will show the backtrace)

steved.

> 
> Regards,
> Vladimir.
> 
> On Sat, 2011-03-19 at 22:19 -0400, Steve Dickson wrote:
>>
>> On 03/19/2011 03:56 AM, Vladimir Elisseev wrote:
>>> Kevin,
>>>
>>> I have some updates. I recompiled nfs-utils and dependencies (libgssglue
>>> keyutils librpcsecgss libtirpc) on the server and on the test client.
>>> Nevertheless, while on the server side I see the same error:
>>> rpc.svcgssd[8390]: qword_eol: fflush failed: errno 22 (Invalid argument)
>>> on the client side rpc.gssd segfault(!):
>>> kernel: rpc.gssd[2107] segfault at 4 ip 0000003ef9430805 sp 00007fff655cdd10 error 4 in libgssapi_krb5.so.2.2[3ef9400000+3e000]
>>> Reverting back to nfs-utils 1.2.2 on the client and everything is fine.
>>> Below are relevant log entries from KDC when using nfs-utils 1.2.2 and 1.2.3 on the client:
>>>
>>> ****** nfs-utils 1.2.2 *******
>>> Mar 19 07:56:27 srv2 krb5kdc[7945]: AS_REQ (7 etypes {18 17 16 23 1 3 2}) 192.168.1.8: ISSUE: authtime 1300517787, etypes {rep=18 tkt=18 ses=18}, host/vbox.xxx.xxx@X.X for krbtgt/X.X@X.X 
>>> Mar 19 07:56:28 srv2 krb5kdc[7945]: TGS_REQ (7 etypes {18 17 16 23 1 3 2}) 192.168.1.8: ISSUE: authtime 1300517787, etypes {rep=18 tkt=18 ses=18}, host/vbox.xxx.xxx@X.X for nfs/nfs.xxx.xxx@X.X 
>>> Mar 19 07:56:28 srv2 krb5kdc[7945]: TGS_REQ (3 etypes {1 3 2}) 192.168.1.8: ISSUE: authtime 1300517787, etypes {rep=18 tkt=18 ses=1}, host/vbox.xxx.xxx@X.X for nfs/nfs.xxx.xxx@X.X 
>>>
>>> ****** nfs-utils 1.2.3 *******
>>> Mar 19 08:22:22 srv2 krb5kdc[7945]: AS_REQ (7 etypes {18 17 16 23 1 3 2}) 192.168.1.2: ISSUE: authtime 1300519342, etypes {rep=18 tkt=18 ses=18}, host/x.x.x@X.X for krbtgt/X.X@X.X 
>>> Mar 19 08:22:22 srv2 krb5kdc[7945]: TGS_REQ (7 etypes {18 17 16 23 1 3 2}) 192.168.1.2: ISSUE: authtime 1300519342, etypes {rep=18 tkt=18 ses=18}, host/x.x.x@X.X for nfs/nfs.x.x@X.X
>>> then
>>> rpc.svcgssd[8390]: qword_eol: fflush failed: errno 22 (Invalid argument) 
>>> and segfault on the client side.
>> Would it be possible to get a back trace from the core?
>>
>> steved.
>