rpc.svcgssd problem after updating client 1.2.2->1.2.3

DISCUSSION Vladimir Elisseev 3 participants 14 messages Mar 17, 2011 – Mar 21, 2011 1 message not in the archive

Subsystems (2)

NFS client NFS server

lore

Share & tools

lore

Vladimir Elisseev

author

2011-03-17 18:54 UTC #0 lore raw

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/[email protected]
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/[email protected]' 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: [email protected], 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/[email protected] while getting keytab entry for 'root/[email protected]' 
Mar 17 17:09:06 user rpc.gssd[32238]: No key table entry found for
nfs/[email protected] while getting keytab entry for 'nfs/[email protected]' 
Mar 17 17:09:06 user rpc.gssd[32238]: Success getting keytab entry for
'host/[email protected]' 
Mar 17 17:09:06 user rpc.gssd[32238]: Successfully obtained machine
credentials for principal 'host/[email protected]' 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
[email protected] 
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

Steve Dickson

2011-03-17 20:57 UTC #1 lore raw

Quoted 11 lines · 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:

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.

Quoted 36 lines

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/[email protected]
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/[email protected]' 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: [email protected], 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

Quoted 1 line

\x6082025106092a864886f71201020201006e8202403082023ca003020105a10302010ea20703050020000000a38201486182014430820140a003020105a10a1b084e45542e484f4d45a21e301ca003020103a11530131b036e66731b0c6e66732e6e65742e686f6d65a382010b30820107a003020112a103020103a281fa0481f76d51de4ee749be6f5662e84fd91220874cd512114a52a7dbb0d1fb96da4768ec9d9f967a9664cc3a27626e0383a6a2e6930123efd709525a41420a68fdaa8fafabfab642f00c4e7d6dc4f075d900adf92f339d02b8ad1a162efeefa7501417280c553a430056634f4771a9bfa86c80eb758e7d530bff6dba5a112ca6b2412123e496a10ef93ac5af820b8751ec53db527acc059fcaee551edab8adc61f1dbc61ed9d16b65157974bd572d25ce62fd8c2e9d30650ef8cd35b12e315535cc1e53895bbd0a9589e02e2de1e62ca61e50e99f2b9f0456157bd3b3d739c6b6899b62f681f91e6072033e62e665ade4c366a1369315f19ca2e7da481da3081d7a003020112a281cf0481cc224de9a1f61431a8aee2b5a4f9fb6260230a0220c87c32030c528c80756b779eea25b272164e1c5e29b4d5be07557039cb7a9e230a5a8572dbe5bec750b952d57022d61ce29643f1110fece4e3c07ba027461e3e865f30a5ed29068cbec2e7a8d1dd18f6

Quoted 54 lines

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/[email protected] while getting keytab entry for 'root/[email protected]' 
Mar 17 17:09:06 user rpc.gssd[32238]: No key table entry found for
nfs/[email protected] while getting keytab entry for 'nfs/[email protected]' 
Mar 17 17:09:06 user rpc.gssd[32238]: Success getting keytab entry for
'host/[email protected]' 
Mar 17 17:09:06 user rpc.gssd[32238]: Successfully obtained machine
credentials for principal 'host/[email protected]' 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
[email protected] 
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 [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

Vladimir Elisseev

author

2011-03-18 06:00 UTC #2 lore raw

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 <[email protected]>
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.

Quoted 11 lines · Steve Dickson

Quoted 9 lines · 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.

Quoted 45 lines

Quoted 2 lines
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.
Quoted 37 lines
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/[email protected]
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/[email protected]' 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: [email protected], 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

Quoted 59 lines

6!
Quoted 46 lines
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/[email protected] while getting keytab entry for 'root/[email protected]' 
Mar 17 17:09:06 user rpc.gssd[32238]: No key table entry found for
nfs/[email protected] while getting keytab entry for 'nfs/[email protected]' 
Mar 17 17:09:06 user rpc.gssd[32238]: Success getting keytab entry for
'host/[email protected]' 
Mar 17 17:09:06 user rpc.gssd[32238]: Successfully obtained machine
credentials for principal 'host/[email protected]' 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
[email protected] 
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
Quoted 8 lines
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 [email protected]
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 [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

Kevin Coffman

2011-03-17 22:13 UTC #3 lore raw

In reply to Vladimir Elisseev

Quoted 43 lines · Vladimir Elisseev

Hello,

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/[email protected]
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/[email protected]' 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: [email protected], 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

Quoted 2 lines

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.

Vladimir Elisseev

author

2011-03-18 05:44 UTC #4 lore raw

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.

Quoted 63 lines · Kevin Coffman

Quoted 43 lines · 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/[email protected]
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/[email protected]' 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: [email protected], 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
Quoted 2 lines
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 [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

Kevin Coffman

2011-03-18 13:35 UTC #5 lore raw

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.

Quoted 82 lines · 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.
Quoted 63 lines · Kevin Coffman
Quoted 43 lines · 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/[email protected]
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/[email protected]' 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: [email protected], 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
Quoted 2 lines
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 [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

Vladimir Elisseev

author

2011-03-18 13:54 UTC #6 lore raw

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 <[email protected]>:

Quoted 4 lines

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.

Quoted 5 lines

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.

Quoted 5 lines

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/[email protected]

Valid starting     Expires            Service principal
03/18/11 06:40:36  03/19/11 06:40:36  krbtgt/[email protected]
         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/[email protected]
         Etype (skey, tkt): des-cbc-crc, aes256-cts-hmac-sha1-96

Quoted 90 lines

K.C.
Quoted 13 lines · 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".
Quoted 69 lines
Regards,
Vladimir.
Quoted 63 lines · Kevin Coffman
Quoted 43 lines · 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/[email protected]
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/[email protected]' 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: [email protected], 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
Quoted 2 lines
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 [email protected]
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 [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

A message that is not in the archive (sent off-list or not yet received): [email protected]

Kevin Coffman

2011-03-18 15:19 UTC #8 lore raw

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.

Quoted 151 lines · 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 <[email protected]>:
Quoted 4 lines
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.
Quoted 5 lines
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.
Quoted 5 lines
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/[email protected]
Valid starting Expires Service principal 03/18/11 06:40:36 03/19/11 06:40:36 krbtgt/[email protected]
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/[email protected]
Etype (skey, tkt): des-cbc-crc, aes256-cts-hmac-sha1-96
Quoted 97 lines
K.C.
Quoted 92 lines · 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.
Quoted 72 lines · Kevin Coffman
Quoted 49 lines · 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/[email protected]
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/[email protected]' 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: [email protected], 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
Quoted 2 lines
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 [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

Vladimir Elisseev

author

2011-03-18 15:48 UTC #9 lore raw

Kevin,

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

Quoting Kevin Coffman <[email protected]>:

Quoted 3 lines

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.

Quoted 7 lines

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 <[email protected]>
Date:   Thu Apr 15 08:32:20 2010 -0400

Try to use kernel function to determine supported Kerberos enctypes.

Quoted 5 lines

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.

Quoted 7 lines

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 ;-)

Quoted 2 lines

K.C.

Regards,
Vladimir.

Quoted 158 lines · Vladimir Elisseev

Quoted 42 lines
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 <[email protected]>:
Quoted 4 lines
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.
Quoted 5 lines
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.
Quoted 5 lines
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/[email protected]
Quoted 109 lines
Valid starting Expires Service principal 03/18/11 06:40:36 03/19/11 06:40:36 krbtgt/[email protected]
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/[email protected]
Etype (skey, tkt): des-cbc-crc, aes256-cts-hmac-sha1-96
Quoted 97 lines
K.C.
Quoted 92 lines · 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.
Quoted 72 lines · Kevin Coffman
Quoted 49 lines · 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/[email protected]
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/[email protected]' 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: [email protected], 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
Quoted 2 lines
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 [email protected]
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 [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

Kevin Coffman

2011-03-18 16:36 UTC #10 lore raw

Quoted 11 lines · Vladimir Elisseev

Kevin,
First of all, thank you for helping me with this issue.
Quoting Kevin Coffman <[email protected]>:
Quoted 3 lines
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.

Quoted 13 lines

Quoted 6 lines
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 <[email protected]>
Date: Thu Apr 15 08:32:20 2010 -0400

Quoted 6 lines

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 <[email protected]>
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.)

Quoted 16 lines

Quoted 4 lines
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.
Quoted 7 lines
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?

Quoted 6 lines

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.

Vladimir Elisseev

author

2011-03-19 07:56 UTC #11 lore raw

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/[email protected] for krbtgt/[email protected] 
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/[email protected] for nfs/[email protected] 
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/[email protected] for nfs/[email protected]

****** 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/[email protected] for krbtgt/[email protected] 
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/[email protected] for nfs/[email protected]

then
rpc.svcgssd[8390]: qword_eol: fflush failed: errno 22 (Invalid argument) and segfault on the client side.

Regards,
Vladimir.

Quoted 83 lines · Kevin Coffman

Quoted 11 lines · Vladimir Elisseev
Kevin,
First of all, thank you for helping me with this issue.
Quoting Kevin Coffman <[email protected]>:
Quoted 3 lines
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.
Quoted 13 lines
Quoted 6 lines
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 <[email protected]>
Date:   Thu Apr 15 08:32:20 2010 -0400
Quoted 6 lines
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 <[email protected]>
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.)
Quoted 16 lines
Quoted 4 lines
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.
Quoted 7 lines
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?
Quoted 6 lines
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 [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

Steve Dickson

2011-03-20 02:19 UTC #12 lore raw

Quoted 16 lines · 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/[email protected] for krbtgt/[email protected] 
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/[email protected] for nfs/[email protected] 
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/[email protected] for nfs/[email protected] 

Quoted 6 lines

****** 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/[email protected] for krbtgt/[email protected] 
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/[email protected] for nfs/[email protected]

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.

Vladimir Elisseev

author

2011-03-21 05:36 UTC #13 lore raw

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.

Quoted 27 lines · Steve Dickson

Quoted 16 lines · 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/[email protected] for krbtgt/[email protected] 
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/[email protected] for nfs/[email protected] 
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/[email protected] for nfs/[email protected] 
Quoted 6 lines
****** 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/[email protected] for krbtgt/[email protected] 
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/[email protected] for nfs/[email protected]
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.

Steve Dickson

2011-03-21 14:30 UTC #14 lore raw

Quoted 9 lines · 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 ...

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.

Quoted 33 lines

Regards,
Vladimir.
Quoted 27 lines · Steve Dickson
Quoted 16 lines · 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/[email protected] for krbtgt/[email protected] 
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/[email protected] for nfs/[email protected] 
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/[email protected] for nfs/[email protected] 
Quoted 6 lines
****** 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/[email protected] for krbtgt/[email protected] 
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/[email protected] for nfs/[email protected]
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.