* Kerberized NFS-Server Problem still present in 3.10.0-rc2
@ 2013-06-19 13:47 Sven Geggus
2013-06-19 21:34 ` J. Bruce Fields
0 siblings, 1 reply; 19+ messages in thread
From: Sven Geggus @ 2013-06-19 13:47 UTC (permalink / raw)
To: linux-nfs
Hello,
I just tried using Kernel 3.10.0-rc2 an my NFS-server test VM and I'm still
unable to run a working kerberized NFS-Server with this kernel.
To make it work I would have to go back to Kernel 3.8.x (which i can't
because I want to use drbd 8.4).
Any hints on how to furter debug this?
As I already said, I failed in "git bisecting" the Problem because the
behaviour changed from broken behaviour (infinite hang) to another broken
behaviour (permission denied) while doing so.
Sven
--
"We don't know the OS that God uses, but the Vatican uses Linux"
(Sister Judith Zoebelein, Vatican Webmaster)
/me is giggls@ircnet, http://sven.gegg.us/ on the Web
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Kerberized NFS-Server Problem still present in 3.10.0-rc2
2013-06-19 13:47 Kerberized NFS-Server Problem still present in 3.10.0-rc2 Sven Geggus
@ 2013-06-19 21:34 ` J. Bruce Fields
2013-06-20 8:03 ` Sven Geggus
0 siblings, 1 reply; 19+ messages in thread
From: J. Bruce Fields @ 2013-06-19 21:34 UTC (permalink / raw)
To: Sven Geggus; +Cc: linux-nfs
On Wed, Jun 19, 2013 at 01:47:20PM +0000, Sven Geggus wrote:
> Hello,
>
> I just tried using Kernel 3.10.0-rc2 an my NFS-server test VM and I'm still
> unable to run a working kerberized NFS-Server with this kernel.
>
> To make it work I would have to go back to Kernel 3.8.x (which i can't
> because I want to use drbd 8.4).
>
> Any hints on how to furter debug this?
>
> As I already said, I failed in "git bisecting" the Problem because the
> behaviour changed from broken behaviour (infinite hang) to another broken
> behaviour (permission denied) while doing so.
Apologies, I don't remember the previous discussion, so, could you
summarize for me?:
- you're able to reproduce/not reproduce the problem by changing
*only* the kernel on the nfs server between 3.8.x and
3.10.0-rc2 ?
- have you figured out exactly where the failure happens?:
- which version of NFS are you using?
Also if you haven't already it would be useful to know at exactly which
step of the process it's failing. As a first step running wireshark on
the traffic between client and server and looking for a NULL
init_sec_context rpc call and seeing whether it succeeds or not, would
be useful.
--b.
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Kerberized NFS-Server Problem still present in 3.10.0-rc2
2013-06-19 21:34 ` J. Bruce Fields
@ 2013-06-20 8:03 ` Sven Geggus
2013-06-20 12:09 ` Sven Geggus
2013-06-20 14:49 ` J. Bruce Fields
0 siblings, 2 replies; 19+ messages in thread
From: Sven Geggus @ 2013-06-20 8:03 UTC (permalink / raw)
To: J. Bruce Fields; +Cc: linux-nfs
J. Bruce Fields schrieb am Mittwoch, den 19. Juni um 23:34 Uhr:
> Apologies, I don't remember the previous discussion, so, could you
> summarize for me?
Shure!
My original bug-report ist here:
http://www.spinics.net/lists/linux-nfs/msg37454.html
> - you're able to reproduce/not reproduce the problem by changing
> *only* the kernel on the nfs server between 3.8.x and
> 3.10.0-rc2 ?
Exactly. See also the Postings of Richard van den Toorn on the list.
Summary: Mount is locking when upgrading from 3.8.x to 3.9.x
Unfortunately I was unable to do a git bisect because somewhere on the way
the behaviour changed from locking to "permission denied".
If you give me a hint if this behaviour should be marked as good or bad I
can continue bisecting!
> - have you figured out exactly where the failure happens?:
No because I have not been able to do git bisect to the end.
> - which version of NFS are you using?
NFS4 with Kerberos authentication.
> Also if you haven't already it would be useful to know at exactly which
> step of the process it's failing. As a first step running wireshark on
> the traffic between client and server and looking for a NULL
> init_sec_context rpc call and seeing whether it succeeds or not, would
> be useful.
I already posted a wireshark dump:
http://www.spinics.net/lists/linux-nfs/msg37472.html
Regards
Sven
--
"Ich fürchte mich nicht vor der Rückkehr der Faschisten in der Maske der
Faschisten, sondern vor der Rückkehr der Faschisten in der Maske der
Demokraten" (Theodor W. Adorno)
/me is giggls@ircnet, http://sven.gegg.us/ on the Web
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Kerberized NFS-Server Problem still present in 3.10.0-rc2
2013-06-20 8:03 ` Sven Geggus
@ 2013-06-20 12:09 ` Sven Geggus
2013-06-20 14:49 ` J. Bruce Fields
1 sibling, 0 replies; 19+ messages in thread
From: Sven Geggus @ 2013-06-20 12:09 UTC (permalink / raw)
To: linux-nfs
Sven Geggus <lists@fuchsschwanzdomain.de> wrote:
> Unfortunately I was unable to do a git bisect because somewhere on the way
> the behaviour changed from locking to "permission denied".
I now just decided, that broken behaviour has to be treated as broken,
regardles of the kind of behaviour thus my git bisect now ended here:
683428fae8c73d7d7da0fa2e0b6beb4d8df4e808 is the first bad commit
commit 683428fae8c73d7d7da0fa2e0b6beb4d8df4e808
Author: Eric W. Biederman <ebiederm@xmission.com>
Date: Sat Feb 2 01:40:53 2013 -0800
sunrpc: Update svcgss xdr handle to rpsec_contect cache
For each received uid call make_kuid and validate the result.
For each received gid call make_kgid and validate the result.
Cc: "J. Bruce Fields" <bfields@fieldses.org>
Cc: Trond Myklebust <Trond.Myklebust@netapp.com>
Signed-off-by: "Eric W. Biederman" <ebiederm@xmission.com>
:040000 040000 15a764b57c7d75a102296c1d151a244e6ec074c964a3a6f19b5a2a4aaf15002b476664d19e68e205 M net
Note, that this is the one which caused permission denied errors rather than
infinite hangs:
mount.nfs4: access denied by server while mounting vnfsrv:/storage
I suspect that it has been "fixed" in a way which is also broken.
Regards
Sven
--
"C Is Quirky, Flawed, And An Enormous Success."
(Dennis M. Ritchie)
/me is giggls@ircnet, http://sven.gegg.us/ on the Web
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Kerberized NFS-Server Problem still present in 3.10.0-rc2
2013-06-20 8:03 ` Sven Geggus
2013-06-20 12:09 ` Sven Geggus
@ 2013-06-20 14:49 ` J. Bruce Fields
2013-06-20 14:52 ` J. Bruce Fields
1 sibling, 1 reply; 19+ messages in thread
From: J. Bruce Fields @ 2013-06-20 14:49 UTC (permalink / raw)
To: Sven Geggus; +Cc: linux-nfs
On Thu, Jun 20, 2013 at 10:03:55AM +0200, Sven Geggus wrote:
> J. Bruce Fields schrieb am Mittwoch, den 19. Juni um 23:34 Uhr:
>
> > Apologies, I don't remember the previous discussion, so, could you
> > summarize for me?
>
> Shure!
> My original bug-report ist here:
> http://www.spinics.net/lists/linux-nfs/msg37454.html
>
> > - you're able to reproduce/not reproduce the problem by changing
> > *only* the kernel on the nfs server between 3.8.x and
> > 3.10.0-rc2 ?
>
> Exactly. See also the Postings of Richard van den Toorn on the list.
>
> Summary: Mount is locking when upgrading from 3.8.x to 3.9.x
>
> Unfortunately I was unable to do a git bisect because somewhere on the way
> the behaviour changed from locking to "permission denied".
>
> If you give me a hint if this behaviour should be marked as good or bad I
> can continue bisecting!
>
> > - have you figured out exactly where the failure happens?:
>
> No because I have not been able to do git bisect to the end.
>
> > - which version of NFS are you using?
>
> NFS4 with Kerberos authentication.
What happens with NFSv3?
> > Also if you haven't already it would be useful to know at exactly which
> > step of the process it's failing. As a first step running wireshark on
> > the traffic between client and server and looking for a NULL
> > init_sec_context rpc call and seeing whether it succeeds or not, would
> > be useful.
>
> I already posted a wireshark dump:
> http://www.spinics.net/lists/linux-nfs/msg37472.html
So it looks it did a null init_sec_context establishment and then the
server didn't reply to the first rpc call using the new context. But
it's hard to be sure without more details--could I get the binary dump?
That might be explained by the problem fixed by
3c34ae11fac3b30629581d0bfaf80f58e82cfbfb "nfsd: fix krb5 handling of
anonymous principals", but that was already in v3.9.
--b.
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Kerberized NFS-Server Problem still present in 3.10.0-rc2
2013-06-20 14:49 ` J. Bruce Fields
@ 2013-06-20 14:52 ` J. Bruce Fields
2013-06-21 8:32 ` Sven Geggus
0 siblings, 1 reply; 19+ messages in thread
From: J. Bruce Fields @ 2013-06-20 14:52 UTC (permalink / raw)
To: Sven Geggus; +Cc: linux-nfs
On Thu, Jun 20, 2013 at 10:49:55AM -0400, J. Bruce Fields wrote:
> On Thu, Jun 20, 2013 at 10:03:55AM +0200, Sven Geggus wrote:
> > J. Bruce Fields schrieb am Mittwoch, den 19. Juni um 23:34 Uhr:
> >
> > > Apologies, I don't remember the previous discussion, so, could you
> > > summarize for me?
> >
> > Shure!
> > My original bug-report ist here:
> > http://www.spinics.net/lists/linux-nfs/msg37454.html
> >
> > > - you're able to reproduce/not reproduce the problem by changing
> > > *only* the kernel on the nfs server between 3.8.x and
> > > 3.10.0-rc2 ?
> >
> > Exactly. See also the Postings of Richard van den Toorn on the list.
> >
> > Summary: Mount is locking when upgrading from 3.8.x to 3.9.x
> >
> > Unfortunately I was unable to do a git bisect because somewhere on the way
> > the behaviour changed from locking to "permission denied".
> >
> > If you give me a hint if this behaviour should be marked as good or bad I
> > can continue bisecting!
> >
> > > - have you figured out exactly where the failure happens?:
> >
> > No because I have not been able to do git bisect to the end.
> >
> > > - which version of NFS are you using?
> >
> > NFS4 with Kerberos authentication.
>
> What happens with NFSv3?
>
> > > Also if you haven't already it would be useful to know at exactly which
> > > step of the process it's failing. As a first step running wireshark on
> > > the traffic between client and server and looking for a NULL
> > > init_sec_context rpc call and seeing whether it succeeds or not, would
> > > be useful.
> >
> > I already posted a wireshark dump:
> > http://www.spinics.net/lists/linux-nfs/msg37472.html
>
> So it looks it did a null init_sec_context establishment and then the
> server didn't reply to the first rpc call using the new context. But
> it's hard to be sure without more details--could I get the binary dump?
>
> That might be explained by the problem fixed by
> 3c34ae11fac3b30629581d0bfaf80f58e82cfbfb "nfsd: fix krb5 handling of
> anonymous principals", but that was already in v3.9.
Hm, or I wonder if 8b5309d41751b8a086d8e7a43abe37d9ff24559d "svcrpc: fix
failures to handle -1 uid's and gid's" (appended) would help.
--b.
commit 8b5309d41751b8a086d8e7a43abe37d9ff24559d
Author: J. Bruce Fields <bfields@redhat.com>
Date: Fri May 24 17:24:34 2013 -0400
svcrpc: fix failures to handle -1 uid's and gid's
As of f025adf191924e3a75ce80e130afcd2485b53bb8 "sunrpc: Properly decode
kuids and kgids in RPC_AUTH_UNIX credentials" any rpc containing a -1
(0xffff) uid or gid would fail with a badcred error.
Reported symptoms were xmbc clients failing on upgrade of the NFS
server; examination of the network trace showed them sending -1 as the
gid.
Reported-by: Julian Sikorski <belegdol@gmail.com>
Cc: "Eric W. Biederman" <ebiederm@xmission.com>
Signed-off-by: J. Bruce Fields <bfields@redhat.com>
diff --git a/net/sunrpc/svcauth_unix.c b/net/sunrpc/svcauth_unix.c
index c3f9e1e..06bdf5a 100644
--- a/net/sunrpc/svcauth_unix.c
+++ b/net/sunrpc/svcauth_unix.c
@@ -810,11 +810,15 @@ svcauth_unix_accept(struct svc_rqst *rqstp, __be32 *authp)
goto badcred;
argv->iov_base = (void*)((__be32*)argv->iov_base + slen); /* skip machname */
argv->iov_len -= slen*4;
-
+ /*
+ * Note: we skip uid_valid()/gid_valid() checks here for
+ * backwards compatibility with clients that use -1 id's.
+ * Instead, -1 uid or gid is later mapped to the
+ * (export-specific) anonymous id by nfsd_setuser.
+ * Supplementary gid's will be left alone.
+ */
cred->cr_uid = make_kuid(&init_user_ns, svc_getnl(argv)); /* uid */
cred->cr_gid = make_kgid(&init_user_ns, svc_getnl(argv)); /* gid */
- if (!uid_valid(cred->cr_uid) || !gid_valid(cred->cr_gid))
- goto badcred;
slen = svc_getnl(argv); /* gids length */
if (slen > 16 || (len -= (slen + 2)*4) < 0)
goto badcred;
@@ -823,8 +827,6 @@ svcauth_unix_accept(struct svc_rqst *rqstp, __be32 *authp)
return SVC_CLOSE;
for (i = 0; i < slen; i++) {
kgid_t kgid = make_kgid(&init_user_ns, svc_getnl(argv));
- if (!gid_valid(kgid))
- goto badcred;
GROUP_AT(cred->cr_group_info, i) = kgid;
}
if (svc_getu32(argv) != htonl(RPC_AUTH_NULL) || svc_getu32(argv) != 0) {
^ permalink raw reply related [flat|nested] 19+ messages in thread
* Re: Kerberized NFS-Server Problem still present in 3.10.0-rc2
2013-06-20 14:52 ` J. Bruce Fields
@ 2013-06-21 8:32 ` Sven Geggus
2013-06-24 21:54 ` J. Bruce Fields
0 siblings, 1 reply; 19+ messages in thread
From: Sven Geggus @ 2013-06-21 8:32 UTC (permalink / raw)
To: J. Bruce Fields; +Cc: linux-nfs
[-- Attachment #1: Type: text/plain, Size: 961 bytes --]
J. Bruce Fields schrieb am Donnerstag, den 20. Juni um 16:52 Uhr:
> What happens with NFSv3?
I have no Idea. I have a NFS4-only Server Setup and would need to enable v3
explicitly.
> So it looks it did a null init_sec_context establishment and then the
> server didn't reply to the first rpc call using the new context. But
> it's hard to be sure without more details--could I get the binary dump?
Attached (Server kernel was 3.10.0-rc2 with patch below).
> Hm, or I wonder if 8b5309d41751b8a086d8e7a43abe37d9ff24559d "svcrpc: fix
> failures to handle -1 uid's and gid's" (appended) would help.
No! I just patched this into a vanilla 3.10.0-rc2. Same Problem. The NFS-mount
just hangs.
Sven
--
"Thinking of using NT for your critical apps?
Isn't there enough suffering in the world?"
(Advertisement of Sun Microsystems in Wall Street Journal)
/me is giggls@ircnet, http://sven.gegg.us/ on the Web
[-- Attachment #2: 3.10.0-rc2-nfs-server.pcap --]
[-- Type: application/cap, Size: 3648 bytes --]
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Kerberized NFS-Server Problem still present in 3.10.0-rc2
2013-06-21 8:32 ` Sven Geggus
@ 2013-06-24 21:54 ` J. Bruce Fields
2013-06-25 9:46 ` Sven Geggus
0 siblings, 1 reply; 19+ messages in thread
From: J. Bruce Fields @ 2013-06-24 21:54 UTC (permalink / raw)
To: Sven Geggus; +Cc: linux-nfs
On Fri, Jun 21, 2013 at 10:32:22AM +0200, Sven Geggus wrote:
> J. Bruce Fields schrieb am Donnerstag, den 20. Juni um 16:52 Uhr:
>
> > What happens with NFSv3?
>
> I have no Idea. I have a NFS4-only Server Setup and would need to enable v3
> explicitly.
>
> > So it looks it did a null init_sec_context establishment and then the
> > server didn't reply to the first rpc call using the new context. But
> > it's hard to be sure without more details--could I get the binary dump?
>
> Attached (Server kernel was 3.10.0-rc2 with patch below).
OK, yes, thanks, the init_sec_context exchange does look acceptable but
the server never responds to the first real rpc (a SETCLIENTID) using
the new context.
Could you run
strace -p $(pidof rpc.svcgssd) -s4096 -e trace=open,close,read,write
on the server while trying this? That should capture the contents of
the relevant upcalls. I wonder if there's something odd about the
context svcgssd is passing down.
> > Hm, or I wonder if 8b5309d41751b8a086d8e7a43abe37d9ff24559d "svcrpc: fix
> > failures to handle -1 uid's and gid's" (appended) would help.
>
> No! I just patched this into a vanilla 3.10.0-rc2. Same Problem. The NFS-mount
> just hangs.
OK, thanks for checking.
--b.
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Kerberized NFS-Server Problem still present in 3.10.0-rc2
2013-06-24 21:54 ` J. Bruce Fields
@ 2013-06-25 9:46 ` Sven Geggus
2013-07-01 12:09 ` Sven Geggus
[not found] ` <20130701205234.GF19945@fieldses.org>
0 siblings, 2 replies; 19+ messages in thread
From: Sven Geggus @ 2013-06-25 9:46 UTC (permalink / raw)
To: J. Bruce Fields; +Cc: nfs
[-- Attachment #1: Type: text/plain, Size: 638 bytes --]
J. Bruce Fields schrieb am Montag, den 24. Juni um 23:54 Uhr:
> Could you run
>
> strace -p $(pidof rpc.svcgssd) -s4096 -e trace=open,close,read,write
>
> on the server while trying this?
Hm how confidential is this information? This is a test-vm only, but should
I re-generate the krb5.keytab of the machine when posting this here?
Anyway, file attached.
Regards
Sven
--
Microsoft ist offenbar die einzige Firma, die in der Lage ist, ein mit
Office nicht kompatibles Bürosoftwarepaket einzuführen.
(Florian Weimer in de.alt.sysadmin.recovery)
/me is giggls@ircnet, http://sven.gegg.us/ on the Web
[-- Attachment #2: svcgssd-trace.txt --]
[-- Type: text/plain, Size: 10278 bytes --]
read(4, "\\x \\x6082051f06092a864886f71201020201006e82050e3082050aa003020105a10302010ea20703050020000000a382040761820403308203ffa003020105a1101b0e50432e494954422e4648472e4445a2273025a003020103a11e301c1b036e66731b15766e667372762e70632e696974622e6668672e6465a38203bb308203b7a003020117a103020102a28203a9048203a569e454c74d63a5e336da118e0d8632d542b66043e3affb1bd63db929ef215409ee7741ba6e47d4caf433076d42c32b7d96cc50c8db418052658d9833354ebd124c660bf375a8fe4fe956315808b5449c53fc15a9e5f7c6dfa1ec03c775a11ceba73e3557186fcac8276ad1fffc1bea70405461dbe104df6df64635439384c124c64eac7514e3dc73fb4413c0c8d57fcda1a799a7b35479692bf59578b689dd831c1295e7544f8928f0f5e774c387663da07d8281a2d5ef524a324ba11c8f749079b85b3c8b23fcf745032c984bc9a5b3bb20c42ed60671e48bb217e5e374fed3d7c38a1e819452779db11f65a66e6c117f4bb727f202081a90699bbf720bc40dbd6fd7db62b6fc1dc86970b6a0e8852159003f2d575d175265a4451dfa622ae2098d6e1443dc274f6870b1402c02b07fa7608837f3a55ac61c3cd40ea8e24256da49f122b271a3101e41eb916ddd7267c1ed0318fa9adc44604851d328d3f8c3662baab909dce2d74dac949324985b50ccb289a4d44de80209203e165dff9b71c9d8c71a2c8badae16f61f7ef389567284d44b163620320eb825de51f4b78425022f19cf703941d316499c7972e96326f046aa951f5181b02e7ac24cb3292cfbee09e8976d4876f68ccf78f6fc802ef920452afb98f05cd0d15c4104c5ae9107ae19e9dbe37e33279b4469f894a2772aff47a92562d44cce438b7cf624d2dd12f95f52db81f136028fc72143359940f694e22b680b756860010bff9b51a7c8ff0a448c54f5490cafa469630ee757fd1158255c0649c7c0270e5783ca5b47038d510f2c80cf4f00ea9157b7f96c3c3d25e082b7cf0a3ed9f5b4c21f8376c4b14fb61ff160a88cc8ec30f128c2b33a2ebd3d1d4052556553aef35d2010b15c105ebfbd7384102052923906bf87ba7dcdd1125ca07641939835d6174a95f9b63b12ee8fa23d7d34c7e1bfaeb278a9387aacd4e01bbe86ec7bbe6f9e255f56a9c441330cf947b916e8b1e807ccdbfe300283b02356eb5138d8153ab18366e9bd69c0573c1e5ddbde934e4e33892bc800817b545db2b54192003892f8b000277fa30e09ee6c90ac7eae605521ec724968439188b04d7fa22da24c36860d283765e3ac9fae8ad0a76e65c253a74d8dc8192f6ffeaf804ae0b08a54886fb289156c062a461d59e1b701824cedb45694922669d659113177c368142fbf9faaf0eddc06e928d7aded58b840e2ef3250433d4e82c0681ecff0916457badb460b43bb27f832e0785a0f0becc25789197276b8b80037cb54db8a3899b56468695bc92e7dea61f9c3d64e31a481e93081e6a003020117a281de0481db9b2606a032a287d3989d99a68691f0b7bc4df43b6fbae0a5a42c3cd069d6cb1437ac745360501c0224e9fab79cb3ba62b2de6af5fa81279701e978f79e0127aab0b8d4f7528c6b733897167abb9be39ed13c245d3bc6dd7d8edf1be5844a3978a36e1f06cbc5c91f45e5cdc892a92a83ceca5ad86b50905a135c7f7c295977f837f5824670e0ed94d6cfdfe8df17b9b1821fa3728d3d56df9282b18cb9da1f755749bccc6cae0650911a52a1466385983467d0c5d814cca39f85adece4a438379f1458d837b1be0764f8b240b16bea9dcf84c0ef697ebff179d94e\n", 4096) = 2636
open("/proc/fs/nfsd/supported_krb5_enctypes", O_RDONLY) = 5
read(5, "18,17,16,23,3,1,2", 4096) = 17
read(5, "", 4096) = 0
close(5) = 0
open("/dev/urandom", O_RDONLY) = 5
read(5, "2\270?\307;\347\n1 \21\372\267\2460\351\262\270\tB\343", 20) = 20
close(5) = 0
open("/dev/urandom", O_RDONLY) = 5
read(5, "\343\370\235>\335d\307\255\377\246\307\242|\213\264\317\336>/\211", 20) = 20
close(5) = 0
open("/dev/urandom", O_RDONLY) = 5
read(5, "\311m\315K.d\207hA\321\323H\201\356\246~zQ\346\177", 20) = 20
close(5) = 0
open("/dev/urandom", O_RDONLY) = 5
read(5, "\251rhT\356\2263\10\352S\271B\36\301\373\244k\234\221x", 20) = 20
close(5) = 0
open("/etc/krb5.keytab", O_RDONLY) = 5
read(5, "\5\2\0\0\0D\0\2\0\16PC.IITB.FHG.DE\0\4host\0\25vnfsrv.pc.iitb.fhg.de\0\0\0\1Q\260nq\2\0\1\0\10\346\2177^\v\302\255\250\0\0\0D\0\2\0\16PC.IITB.FHG.DE\0\4host\0\25vnfsrv.pc.iitb.fhg.de\0\0\0\1Q\260nq\2\0\3\0\10\346\2177^\v\302\255\250\0\0\0L\0\2\0\16PC.IITB.FHG.DE\0\4host\0\25vnfsrv.pc.iitb.fhg.de\0\0\0\1Q\260nq\2\0\27\0\20\200\205\364\330\203\321\331]\36\16\0105'\242\377C\0\0\0005\0\2\0\16PC.IITB.FHG.DE\0\4host\0\6VNFSRV\0\0\0\1Q\260nq\2\0\1\0\10\346\2177^\v\302\255\250\0\0\0005\0\2\0\16PC.IITB.FHG.DE\0\4host\0\6VNFSRV\0\0\0\1Q\260nq\2\0\3\0\10\346\2177^\v\302\255\250\0\0\0=\0\2\0\16PC.IITB.FHG.DE\0\4host\0\6VNFSRV\0\0\0\1Q\260nq\2\0\27\0\20\200\205\364\330\203\321\331]\36\16\0105'\242\377C\0\0\0000\0\1\0\16PC.IITB.FHG.DE\0\7VNFSRV$\0\0\0\1Q\260nq\2\0\1\0\10\346\2177^\v\302\255\250\0\0\0000\0\1\0\16PC.IITB.FHG.DE\0\7VNFSRV$\0\0\0\1Q\260nq\2\0\3\0\10\346\2177^\v\302\255\250\0\0\0008\0\1\0\16PC.IITB.FHG.DE\0\7VNFSRV$\0\0\0\1Q\260nq\2\0\27\0\20\200\205\364\330\203\321\331]\36\16\0105'\242\377C\0\0\0C\0\2\0\16PC.IITB.FHG.DE\0\3nfs\0\25vnfsrv.pc.iitb.fhg.de\0\0\0\1Q\260n\231\2\0\1\0\10\346\2177^\v\302\255\250\0\0\0C\0\2\0\16PC.IITB.FHG.DE\0\3nfs\0\25vnfsrv.pc.iitb.fhg.de\0\0\0\1Q\260n\231\2\0\3\0\10\346\2177^\v\302\255\250\0\0\0K\0\2\0\16PC.IITB.FHG.DE\0\3nfs\0\25vnfsrv.pc.iitb.fhg.de\0\0\0\1Q\260n\231\2\0\27\0\20\200\205\364\330\203\321\331]\36\16\0105'\242\377C\0\0\0004\0\2\0\16PC.IITB.FHG.DE\0\3nfs\0\6VNFSRV\0\0\0\1Q\260n\231\2\0\1\0\10\346\2177^\v\302\255\250\0\0\0004\0\2\0\16PC.IITB.FHG.DE\0\3nfs\0\6VNFSRV\0\0\0\1Q\260n\232\2\0\3\0\10\346\2177^\v\302\255\250\0\0\0<\0\2\0\16PC.IITB.FHG.DE\0\3nfs\0\6VNFSRV\0\0\0\1Q\260n\232\2\0\27\0\20\200\205\364\330\203\321\331]\36\16\0105'\242\377C", 8192) = 966
close(5) = 0
write(3, "\1\0\0\0\0k\0\0\0HASH:AD338CB0C424A414DBAC3710F3651714 21:VENUS$@PC.IITB.FHG.DE 40:nfs/vnfsrv.pc.iitb.fhg.de@PC.IITB.FHG.DE\0E\200\7\0\200e\311Q\26\0\0\0VENUS$@PC.IITB.FHG.DE\0)\0\0\0nfs/vnfsrv.pc.iitb.fhg.de@PC.IITB.FHG.DE\0E\200\7\0\200e\311Q", 203) = 203
open("/usr/lib/krb5/plugins/authdata", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/usr/lib/krb5/plugins/authdata", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/dev/urandom", O_RDONLY) = 5
read(5, "\362\223F\31\237\250\277iP\200\256\270\251\204>\345\276\376r\230", 20) = 20
close(5) = 0
open("/dev/urandom", O_RDONLY) = 5
read(5, "\225tEV\331\306\220\305\251!o\316.X\273\v*\312B\345", 20) = 20
close(5) = 0
open("/dev/urandom", O_RDONLY) = 5
read(5, "HB.i\335\252\266m\22Vo)\210j\261\177\253\346\303m", 20) = 20
close(5) = 0
read(5, "\2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\377\377\377\377\377\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0", 36) = 36
close(5) = 0
open("/dev/urandom", O_RDONLY) = 5
read(5, "\366\3\247\370\217\21.\310\335\200\357\350&Z\1\350\304\r2c", 20) = 20
close(5) = 0
open("/proc/net/rpc/auth.rpcsec.context/channel", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 5
write(5, "\\x04000000 1372181158 -1 -1 0 krb5 \\x06000000a6d2c9517da62c3700000000120000008b9e7cb53082bca36502670079249e8e2c44aab7f8713ff9b09225c10f6a2057 \n", 143) = 143
close(5) = 0
open("/proc/net/rpc/auth.rpcsec.init/channel", O_WRONLY) = 5
write(5, "\\x \\x6082051f06092a864886f71201020201006e82050e3082050aa003020105a10302010ea20703050020000000a382040761820403308203ffa003020105a1101b0e50432e494954422e4648472e4445a2273025a003020103a11e301c1b036e66731b15766e667372762e70632e696974622e6668672e6465a38203bb308203b7a003020117a103020102a28203a9048203a569e454c74d63a5e336da118e0d8632d542b66043e3affb1bd63db929ef215409ee7741ba6e47d4caf433076d42c32b7d96cc50c8db418052658d9833354ebd124c660bf375a8fe4fe956315808b5449c53fc15a9e5f7c6dfa1ec03c775a11ceba73e3557186fcac8276ad1fffc1bea70405461dbe104df6df64635439384c124c64eac7514e3dc73fb4413c0c8d57fcda1a799a7b35479692bf59578b689dd831c1295e7544f8928f0f5e774c387663da07d8281a2d5ef524a324ba11c8f749079b85b3c8b23fcf745032c984bc9a5b3bb20c42ed60671e48bb217e5e374fed3d7c38a1e819452779db11f65a66e6c117f4bb727f202081a90699bbf720bc40dbd6fd7db62b6fc1dc86970b6a0e8852159003f2d575d175265a4451dfa622ae2098d6e1443dc274f6870b1402c02b07fa7608837f3a55ac61c3cd40ea8e24256da49f122b271a3101e41eb916ddd7267c1ed0318fa9adc44604851d328d3f8c3662baab909dce2d74dac949324985b50ccb289a4d44de80209203e165dff9b71c9d8c71a2c8badae16f61f7ef389567284d44b163620320eb825de51f4b78425022f19cf703941d316499c7972e96326f046aa951f5181b02e7ac24cb3292cfbee09e8976d4876f68ccf78f6fc802ef920452afb98f05cd0d15c4104c5ae9107ae19e9dbe37e33279b4469f894a2772aff47a92562d44cce438b7cf624d2dd12f95f52db81f136028fc72143359940f694e22b680b756860010bff9b51a7c8ff0a448c54f5490cafa469630ee757fd1158255c0649c7c0270e5783ca5b47038d510f2c80cf4f00ea9157b7f96c3c3d25e082b7cf0a3ed9f5b4c21f8376c4b14fb61ff160a88cc8ec30f128c2b33a2ebd3d1d4052556553aef35d2010b15c105ebfbd7384102052923906bf87ba7dcdd1125ca07641939835d6174a95f9b63b12ee8fa23d7d34c7e1bfaeb278a9387aacd4e01bbe86ec7bbe6f9e255f56a9c441330cf947b916e8b1e807ccdbfe300283b02356eb5138d8153ab18366e9bd69c0573c1e5ddbde934e4e33892bc800817b545db2b54192003892f8b000277fa30e09ee6c90ac7eae605521ec724968439188b04d7fa22da24c36860d283765e3ac9fae8ad0a76e65c253a74d8dc8192f6ffeaf804ae0b08a54886fb289156c062a461d59e1b701824cedb45694922669d659113177c368142fbf9faaf0eddc06e928d7aded58b840e2ef3250433d4e82c0681ecff0916457badb460b43bb27f832e0785a0f0becc25789197276b8b80037cb54db8a3899b56468695bc92e7dea61f9c3d64e31a481e93081e6a003020117a281de0481db9b2606a032a287d3989d99a68691f0b7bc4df43b6fbae0a5a42c3cd069d6cb1437ac745360501c0224e9fab79cb3ba62b2de6af5fa81279701e978f79e0127aab0b8d4f7528c6b733897167abb9be39ed13c245d3bc6dd7d8edf1be5844a3978a36e1f06cbc5c91f45e5cdc892a92a83ceca5ad86b50905a135c7f7c295977f837f5824670e0ed94d6cfdfe8df17b9b1821fa3728d3d56df9282b18cb9da1f755749bccc6cae0650911a52a1466385983467d0c5d814cca39f85adece4a438379f1458d837b1be0764f8b240b16bea9dcf84c0ef697ebff179d94e 1372153276 0 0 \\x04000000 \\x60819506092a864886f71201020202006f8185308182a003020105a10302010fa2763074a003020117a26d046b7f28020fbc8a21e2262984e72f679f2f479ca8f65781d8036441108e5e766292155e35b9549677886209f827195b561bda2333f4b66e51805385abbfb1e7ff1b676621aad8408d218530cfde68aaf4fc6513f1d07c87a2007b1c5d44c8d2f5d6acb47bc569f9faeff1ac7a \n", 2970) = 2970
close(5) = 0
open("/dev/urandom", O_RDONLY) = 5
read(5, "\354\345pp@\231!\215\232r-5>\366\226\306\245\305\363\355", 20) = 20
close(5) = 0
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Kerberized NFS-Server Problem still present in 3.10.0-rc2
2013-06-25 9:46 ` Sven Geggus
@ 2013-07-01 12:09 ` Sven Geggus
[not found] ` <20130701205234.GF19945@fieldses.org>
1 sibling, 0 replies; 19+ messages in thread
From: Sven Geggus @ 2013-07-01 12:09 UTC (permalink / raw)
To: linux-nfs
Just an update on this. I tried to compile Linux 3.10 now and updated
my userland to nfs-utils 1.2.8 (from Debian unstable).
The Problem persists. NFS-Server stops working ith any vaniall Kernel newer
than 3.8.x including 3.10.
Sven
--
Um Kontrolle Ihres Kontos wiederzugewinnen, klicken Sie bitte auf das
Verbindungsgebrüll. (aus einer Ebay fishing Mail)
/me is giggls@ircnet, http://sven.gegg.us/ on the Web
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Kerberized NFS-Server Problem still present in 3.10.0-rc2
[not found] ` <20130701205234.GF19945@fieldses.org>
@ 2013-07-02 8:05 ` Sven Geggus
[not found] ` <20130705181859.GA8288@fieldses.org>
0 siblings, 1 reply; 19+ messages in thread
From: Sven Geggus @ 2013-07-02 8:05 UTC (permalink / raw)
To: J. Bruce Fields; +Cc: nfs
J. Bruce Fields schrieb am Montag, den 01. Juli um 22:52 Uhr:
> It includes the contents of /etc/krb5.keytab, so I'm guessing so.
The server is a test-vm anyway.
> It'd be interesting to know exactly where nfsd decides to drop the
> rpc that uses this new context.... Turning on all the nfsd and rpc
> debugging *might* help there. (rpcdebug -m rpc -s all; rpcdebug -m nfsd
> -s all).
~/ # rpcdebug -m rpc -s all
rpc xprt call debug nfs auth bind sched trans svcsock svcdsp misc cache
~/ # rpcdebug -m nfsd -s all
nfsd sock fh export svc proc fileop auth repcache xdr lockd
Here is what I get (Kernel is vanilla 3.10.0):
Jul 2 09:52:41 vnfsrv kernel: Installing knfsd (copyright (C) 1996 okir@monad.swb.de).
Jul 2 09:52:41 vnfsrv kernel: NFSD: Using /var/lib/nfs/v4recovery as the NFSv4 state recovery directory
Jul 2 09:52:41 vnfsrv kernel: NFSD: starting 90-second grace period (net ffffffff81556500)
Jul 2 09:54:11 vnfsrv kernel: NFSD: laundromat service - starting
Jul 2 09:54:11 vnfsrv kernel: NFSD: end of grace period
Jul 2 09:54:11 vnfsrv kernel: NFSD: laundromat_main - sleeping for 90 seconds
Jul 2 09:55:42 vnfsrv kernel: NFSD: laundromat service - starting
Jul 2 09:55:42 vnfsrv kernel: NFSD: laundromat_main - sleeping for 90 seconds
Jul 2 09:56:42 vnfsrv kernel: svc: socket ffff8800167aad40 TCP (listen) state change 10
Jul 2 09:56:42 vnfsrv kernel: svc: transport ffff8800159c0000 served by daemon ffff88001657a000
Jul 2 09:56:42 vnfsrv kernel: svc: socket ffff8800162147c0 TCP (listen) state change 1
Jul 2 09:56:42 vnfsrv kernel: svc: tcp_accept ffff8800159c0000 sock ffff880016a2e840
Jul 2 09:56:42 vnfsrv kernel: nfsd: connect from 10.1.7.30, port=740
Jul 2 09:56:42 vnfsrv kernel: svc: svc_setup_socket ffff880016a2ed40
Jul 2 09:56:42 vnfsrv kernel: setting up TCP socket for reading
Jul 2 09:56:42 vnfsrv kernel: svc: svc_setup_socket created ffff880015259000 (inet ffff8800162147c0)
Jul 2 09:56:42 vnfsrv kernel: svc: transport ffff880015259000 served by daemon ffff8800167cc000
Jul 2 09:56:42 vnfsrv kernel: svc: server ffff8800167cc000, pool 0, transport ffff880015259000, inuse=3
Jul 2 09:56:42 vnfsrv kernel: svc: tcp_recv ffff880015259000 data 1 conn 0 close 0
Jul 2 09:56:42 vnfsrv kernel: svc: socket ffff880015259000 recvfrom(ffff8800152592a4, 0) = 4
Jul 2 09:56:42 vnfsrv kernel: svc: TCP record, 40 bytes
Jul 2 09:56:42 vnfsrv kernel: svc: socket ffff880015259000 recvfrom(ffff88001607c028, 4056) = 40
Jul 2 09:56:42 vnfsrv kernel: svc: TCP final record (40 bytes)
Jul 2 09:56:42 vnfsrv kernel: svc: got len=40
Jul 2 09:56:42 vnfsrv kernel: svc: svc_authenticate (0)
Jul 2 09:56:42 vnfsrv kernel: svc: transport ffff8800159c0000 served by daemon ffff880016576000
Jul 2 09:56:42 vnfsrv kernel: svc: tcp_accept ffff8800159c0000 sock ffff880016a2e840
Jul 2 09:56:42 vnfsrv kernel: svc: server ffff880016576000 waiting for data (to = 900000)
Jul 2 09:56:42 vnfsrv kernel: svc: calling dispatcher
Jul 2 09:56:42 vnfsrv kernel: svc: server ffff88001657a000 waiting for data (to = 900000)
Jul 2 09:56:42 vnfsrv kernel: nfsd_dispatch: vers 4 proc 0
Jul 2 09:56:42 vnfsrv kernel: svc: socket ffff880015259000 sendto([ffff8800165d4000 28... ], 28) = 28 (addr 10.1.7.30, port=740)
Jul 2 09:56:42 vnfsrv kernel: svc: server ffff8800167cc000 waiting for data (to = 900000)
Jul 2 09:56:42 vnfsrv kernel: svc: socket ffff8800167aad40 TCP (listen) state change 10
Jul 2 09:56:42 vnfsrv kernel: svc: transport ffff8800159c0000 served by daemon ffff8800167cc000
Jul 2 09:56:42 vnfsrv kernel: svc: socket ffff880015277500 TCP (listen) state change 1
Jul 2 09:56:42 vnfsrv kernel: svc: tcp_accept ffff8800159c0000 sock ffff880016a2e840
Jul 2 09:56:42 vnfsrv kernel: \x014nfsd: connect from unprivileged port: 10.1.7.30, port=55093
Jul 2 09:56:42 vnfsrv kernel: nfsd: connect from 10.1.7.30, port=55093
Jul 2 09:56:42 vnfsrv kernel: svc: svc_setup_socket ffff880016a10d00
Jul 2 09:56:43 vnfsrv kernel: setting up TCP socket for reading
Jul 2 09:56:43 vnfsrv kernel: svc: svc_setup_socket created ffff8800158ce000 (inet ffff880015277500)
Jul 2 09:56:43 vnfsrv kernel: svc: transport ffff8800158ce000 served by daemon ffff88001657a000
Jul 2 09:56:43 vnfsrv kernel: svc: server ffff88001657a000, pool 0, transport ffff8800158ce000, inuse=3
Jul 2 09:56:43 vnfsrv kernel: svc: tcp_recv ffff8800158ce000 data 1 conn 0 close 0
Jul 2 09:56:43 vnfsrv kernel: svc: socket ffff8800158ce000 recvfrom(ffff8800158ce2a4, 0) = 4
Jul 2 09:56:43 vnfsrv kernel: svc: TCP record, 1380 bytes
Jul 2 09:56:43 vnfsrv kernel: svc: socket ffff8800158ce000 recvfrom(ffff880016570564, 2716) = 1380
Jul 2 09:56:43 vnfsrv kernel: svc: TCP final record (1380 bytes)
Jul 2 09:56:43 vnfsrv kernel: svc: transport ffff8800159c0000 served by daemon ffff880016576000
Jul 2 09:56:43 vnfsrv kernel: svc: tcp_accept ffff8800159c0000 sock ffff880016a2e840
Jul 2 09:56:43 vnfsrv kernel: svc: server ffff880016576000 waiting for data (to = 900000)
Jul 2 09:56:43 vnfsrv kernel: svc: server ffff8800167cc000 waiting for data (to = 900000)
Jul 2 09:56:43 vnfsrv kernel: svc: got len=1380
Jul 2 09:56:43 vnfsrv kernel: svc: svc_authenticate (6)
Jul 2 09:56:43 vnfsrv kernel: RPC: svcauth_gss: argv->iov_len = 1352
Jul 2 09:56:43 vnfsrv kernel: RPC: Want update, refage=120, age=0
Jul 2 09:56:43 vnfsrv kernel: RPC: krb5_encrypt returns 0
Jul 2 09:56:43 vnfsrv kernel: RPC: krb5_encrypt returns 0
Jul 2 09:56:43 vnfsrv kernel: RPC: krb5_encrypt returns 0
Jul 2 09:56:43 vnfsrv kernel: RPC: krb5_encrypt returns 0
Jul 2 09:56:43 vnfsrv kernel: RPC: krb5_encrypt returns 0
Jul 2 09:56:43 vnfsrv kernel: RPC: krb5_encrypt returns 0
Jul 2 09:56:43 vnfsrv kernel: RPC: krb5_encrypt returns 0
Jul 2 09:56:43 vnfsrv kernel: RPC: krb5_encrypt returns 0
Jul 2 09:56:43 vnfsrv kernel: RPC: krb5_encrypt returns 0
Jul 2 09:56:43 vnfsrv kernel: RPC: krb5_encrypt returns 0
Jul 2 09:56:43 vnfsrv kernel: RPC: krb5_encrypt returns 0
Jul 2 09:56:43 vnfsrv kernel: RPC: krb5_encrypt returns 0
Jul 2 09:56:43 vnfsrv kernel: RPC: gss_import_sec_context_kerberos: returning 0
Jul 2 09:56:43 vnfsrv kernel: RPC: gss_get_mic_v2
Jul 2 09:56:43 vnfsrv kernel: svc: socket ffff8800158ce000 sendto([ffff880016571000 232... ], 232) = 232 (addr 10.1.7.30, port=55093)
Jul 2 09:56:43 vnfsrv kernel: svc: socket ffff880015277500 TCP data ready (svsk ffff8800158ce000)
Jul 2 09:56:43 vnfsrv kernel: svc: transport ffff8800158ce000 served by daemon ffff880016576000
Jul 2 09:56:43 vnfsrv kernel: svc: socket ffff880015277500 TCP (connected) state change 8 (svsk ffff8800158ce000)
Jul 2 09:56:43 vnfsrv kernel: svc: transport ffff8800158ce000 busy, not enqueued
Jul 2 09:56:43 vnfsrv kernel: svc: socket ffff880015277500 TCP data ready (svsk ffff8800158ce000)
Jul 2 09:56:43 vnfsrv kernel: svc: transport ffff8800158ce000 busy, not enqueued
Jul 2 09:56:43 vnfsrv kernel: svc: socket ffff8800162147c0 TCP data ready (svsk ffff880015259000)
Jul 2 09:56:43 vnfsrv kernel: svc: transport ffff880015259000 served by daemon ffff8800167cc000
Jul 2 09:56:43 vnfsrv kernel: svc_recv: found XPT_CLOSE
Jul 2 09:56:43 vnfsrv kernel: svc: svc_delete_xprt(ffff8800158ce000)
Jul 2 09:56:43 vnfsrv kernel: svc: svc_tcp_sock_detach(ffff8800158ce000)
Jul 2 09:56:43 vnfsrv kernel: svc: server ffff8800167cc000, pool 0, transport ffff880015259000, inuse=2
Jul 2 09:56:43 vnfsrv kernel: svc: tcp_recv ffff880015259000 data 1 conn 0 close 0
Jul 2 09:56:43 vnfsrv kernel: svc: socket ffff880015259000 recvfrom(ffff8800152592a4, 0) = 4
Jul 2 09:56:43 vnfsrv kernel: svc: svc_sock_detach(ffff8800158ce000)
Jul 2 09:56:43 vnfsrv kernel: svc: server ffff880016576000 waiting for data (to = 900000)
Jul 2 09:56:43 vnfsrv kernel: svc: transport ffff8800158ce000 busy, not enqueued
Jul 2 09:56:43 vnfsrv kernel: svc: svc_sock_free(ffff8800158ce000)
Jul 2 09:56:43 vnfsrv kernel: svc: server ffff88001657a000 waiting for data (to = 900000)
Jul 2 09:56:43 vnfsrv kernel: svc: TCP record, 200 bytes
Jul 2 09:56:43 vnfsrv kernel: svc: socket ffff880015259000 recvfrom(ffff88001607c0c8, 3896) = 200
Jul 2 09:56:43 vnfsrv kernel: svc: TCP final record (200 bytes)
Jul 2 09:56:43 vnfsrv kernel: svc: got len=200
Jul 2 09:56:43 vnfsrv kernel: svc: svc_authenticate (6)
Jul 2 09:56:43 vnfsrv kernel: RPC: svcauth_gss: argv->iov_len = 172
Jul 2 09:56:43 vnfsrv kernel: RPC: gss_verify_mic_v2
Jul 2 09:56:43 vnfsrv kernel: RPC: gss_get_mic_v2
Jul 2 09:56:43 vnfsrv kernel: RPC: Want update, refage=120, age=0
Jul 2 09:56:43 vnfsrv kernel: RPC: Want update, refage=120, age=0
Jul 2 09:56:48 vnfsrv kernel: svc: svc_process dropit
Jul 2 09:56:48 vnfsrv kernel: svc: xprt ffff880015259000 dropped request
Jul 2 09:56:48 vnfsrv kernel: svc: server ffff8800167cc000 waiting for data (to = 900000)
Jul 2 09:57:12 vnfsrv kernel: NFSD: laundromat service - starting
Jul 2 09:57:12 vnfsrv kernel: NFSD: laundromat_main - sleeping for 90 seconds
Jul 2 09:57:42 vnfsrv kernel: RPC: xs_close xprt ffff88001610b800
Jul 2 09:57:42 vnfsrv kernel: RPC: disconnected transport ffff88001610b800
Jul 2 09:57:42 vnfsrv kernel: RPC: wake_up_first(ffff88001610b978 "xprt_sending")
Jul 2 09:57:44 vnfsrv kernel: svc: socket ffff8800162147c0 TCP (connected) state change 8 (svsk ffff880015259000)
Jul 2 09:57:44 vnfsrv kernel: svc: transport ffff880015259000 served by daemon ffff8800167cc000
Jul 2 09:57:44 vnfsrv kernel: svc: socket ffff8800162147c0 TCP data ready (svsk ffff880015259000)
Jul 2 09:57:44 vnfsrv kernel: svc: transport ffff880015259000 busy, not enqueued
Jul 2 09:57:44 vnfsrv kernel: svc_recv: found XPT_CLOSE
Jul 2 09:57:44 vnfsrv kernel: svc: svc_delete_xprt(ffff880015259000)
Jul 2 09:57:44 vnfsrv kernel: svc: svc_tcp_sock_detach(ffff880015259000)
Jul 2 09:57:44 vnfsrv kernel: svc: svc_sock_detach(ffff880015259000)
Jul 2 09:57:44 vnfsrv kernel: svc: server ffff8800167cc000 waiting for data (to = 900000)
Jul 2 09:57:44 vnfsrv kernel: svc: socket ffff8800167aad40 TCP (listen) state change 10
Jul 2 09:57:44 vnfsrv kernel: svc: transport ffff8800159c0000 served by daemon ffff880016576000
Jul 2 09:57:44 vnfsrv kernel: svc: socket ffff8800164ed540 TCP (listen) state change 1
Jul 2 09:57:44 vnfsrv kernel: svc: tcp_accept ffff8800159c0000 sock ffff880016a2e840
Jul 2 09:57:44 vnfsrv kernel: nfsd: connect from 10.1.7.30, port=740
Jul 2 09:57:44 vnfsrv kernel: svc: svc_setup_socket ffff880016a2eac0
Jul 2 09:57:44 vnfsrv kernel: setting up TCP socket for reading
Jul 2 09:57:44 vnfsrv kernel: svc: svc_setup_socket created ffff88001669a000 (inet ffff8800164ed540)
Jul 2 09:57:44 vnfsrv kernel: svc: transport ffff88001669a000 served by daemon ffff8800167cc000
Jul 2 09:57:44 vnfsrv kernel: svc: server ffff8800167cc000, pool 0, transport ffff88001669a000, inuse=3
Jul 2 09:57:44 vnfsrv kernel: svc: tcp_recv ffff88001669a000 data 1 conn 0 close 0
Jul 2 09:57:44 vnfsrv kernel: svc: socket ffff88001669a000 recvfrom(ffff88001669a2a4, 0) = 4
Jul 2 09:57:44 vnfsrv kernel: svc: TCP record, 200 bytes
Jul 2 09:57:44 vnfsrv kernel: svc: socket ffff88001669a000 recvfrom(ffff88001607c0c8, 3896) = 200
Jul 2 09:57:44 vnfsrv kernel: svc: TCP final record (200 bytes)
Jul 2 09:57:44 vnfsrv kernel: svc: transport ffff8800159c0000 served by daemon ffff88001657a000
Jul 2 09:57:44 vnfsrv kernel: svc: tcp_accept ffff8800159c0000 sock ffff880016a2e840
Jul 2 09:57:44 vnfsrv kernel: svc: server ffff88001657a000 waiting for data (to = 900000)
Jul 2 09:57:44 vnfsrv kernel: svc: server ffff880016576000 waiting for data (to = 900000)
Jul 2 09:57:44 vnfsrv kernel: svc: got len=200
Jul 2 09:57:44 vnfsrv kernel: svc: svc_authenticate (6)
Jul 2 09:57:44 vnfsrv kernel: RPC: svcauth_gss: argv->iov_len = 172
Jul 2 09:57:44 vnfsrv kernel: RPC: gss_verify_mic_v2
Jul 2 09:57:44 vnfsrv kernel: RPC: gss_get_mic_v2
Jul 2 09:57:44 vnfsrv kernel: RPC: Want update, refage=120, age=61
Jul 2 09:57:49 vnfsrv kernel: svc: svc_process dropit
Jul 2 09:57:49 vnfsrv kernel: svc: xprt ffff88001669a000 dropped request
Jul 2 09:57:49 vnfsrv kernel: svc: server ffff8800167cc000 waiting for data (to = 900000)
Jul 2 09:58:42 vnfsrv kernel: NFSD: laundromat service - starting
Jul 2 09:58:42 vnfsrv kernel: NFSD: laundromat_main - sleeping for 90 seconds
Jul 2 09:59:45 vnfsrv kernel: svc: socket ffff8800164ed540 TCP (connected) state change 8 (svsk ffff88001669a000)
Jul 2 09:59:45 vnfsrv kernel: svc: transport ffff88001669a000 served by daemon ffff8800167cc000
Jul 2 09:59:45 vnfsrv kernel: svc: socket ffff8800164ed540 TCP data ready (svsk ffff88001669a000)
Jul 2 09:59:45 vnfsrv kernel: svc: transport ffff88001669a000 busy, not enqueued
Jul 2 09:59:45 vnfsrv kernel: svc_recv: found XPT_CLOSE
Jul 2 09:59:45 vnfsrv kernel: svc: svc_delete_xprt(ffff88001669a000)
Jul 2 09:59:45 vnfsrv kernel: svc: svc_tcp_sock_detach(ffff88001669a000)
Jul 2 09:59:45 vnfsrv kernel: svc: svc_sock_detach(ffff88001669a000)
Jul 2 09:59:45 vnfsrv kernel: svc: server ffff8800167cc000 waiting for data (to = 900000)
Jul 2 09:59:46 vnfsrv kernel: svc: socket ffff8800167aad40 TCP (listen) state change 10
Jul 2 09:59:46 vnfsrv kernel: svc: transport ffff8800159c0000 served by daemon ffff8800167cc000
Jul 2 09:59:46 vnfsrv kernel: svc: socket ffff88001503f440 TCP (listen) state change 1
Jul 2 09:59:46 vnfsrv kernel: svc: tcp_accept ffff8800159c0000 sock ffff880016a2e840
Jul 2 09:59:46 vnfsrv kernel: nfsd: connect from 10.1.7.30, port=740
Jul 2 09:59:46 vnfsrv kernel: svc: svc_setup_socket ffff880016accd40
Jul 2 09:59:46 vnfsrv kernel: setting up TCP socket for reading
Jul 2 09:59:46 vnfsrv kernel: svc: svc_setup_socket created ffff8800159f0000 (inet ffff88001503f440)
Jul 2 09:59:46 vnfsrv kernel: svc: transport ffff8800159f0000 served by daemon ffff880016576000
Jul 2 09:59:46 vnfsrv kernel: svc: server ffff880016576000, pool 0, transport ffff8800159f0000, inuse=3
Jul 2 09:59:46 vnfsrv kernel: svc: tcp_recv ffff8800159f0000 data 1 conn 0 close 0
Jul 2 09:59:46 vnfsrv kernel: svc: socket ffff8800159f0000 recvfrom(ffff8800159f02a4, 0) = 4
Jul 2 09:59:46 vnfsrv kernel: svc: TCP record, 200 bytes
Jul 2 09:59:46 vnfsrv kernel: svc: transport ffff8800159c0000 served by daemon ffff88001657a000
Jul 2 09:59:46 vnfsrv kernel: svc: tcp_accept ffff8800159c0000 sock ffff880016a2e840
Jul 2 09:59:46 vnfsrv kernel: svc: server ffff88001657a000 waiting for data (to = 900000)
Jul 2 09:59:46 vnfsrv kernel: svc: server ffff8800167cc000 waiting for data (to = 900000)
Jul 2 09:59:46 vnfsrv kernel: svc: socket ffff8800159f0000 recvfrom(ffff8800166f80c8, 3896) = 200
Jul 2 09:59:46 vnfsrv kernel: svc: TCP final record (200 bytes)
Jul 2 09:59:46 vnfsrv kernel: svc: got len=200
Jul 2 09:59:46 vnfsrv kernel: svc: svc_authenticate (6)
Jul 2 09:59:46 vnfsrv kernel: RPC: svcauth_gss: argv->iov_len = 172
Jul 2 09:59:46 vnfsrv kernel: RPC: gss_verify_mic_v2
Jul 2 09:59:46 vnfsrv kernel: RPC: gss_get_mic_v2
Jul 2 09:59:46 vnfsrv kernel: RPC: Want update, refage=120, age=0
Jul 2 09:59:51 vnfsrv kernel: svc: svc_process dropit
Jul 2 09:59:51 vnfsrv kernel: svc: xprt ffff8800159f0000 dropped request
Jul 2 09:59:51 vnfsrv kernel: svc: server ffff880016576000 waiting for data (to = 900000)
Jul 2 10:00:12 vnfsrv kernel: NFSD: laundromat service - starting
Jul 2 10:00:12 vnfsrv kernel: NFSD: laundromat_main - sleeping for 90 seconds
Jul 2 10:00:47 vnfsrv kernel: svc: socket ffff88001503f440 TCP (connected) state change 8 (svsk ffff8800159f0000)
Jul 2 10:00:47 vnfsrv kernel: svc: transport ffff8800159f0000 served by daemon ffff880016576000
Jul 2 10:00:47 vnfsrv kernel: svc: socket ffff88001503f440 TCP data ready (svsk ffff8800159f0000)
Jul 2 10:00:47 vnfsrv kernel: svc: transport ffff8800159f0000 busy, not enqueued
Jul 2 10:00:47 vnfsrv kernel: svc_recv: found XPT_CLOSE
Jul 2 10:00:47 vnfsrv kernel: svc: svc_delete_xprt(ffff8800159f0000)
Jul 2 10:00:47 vnfsrv kernel: svc: svc_tcp_sock_detach(ffff8800159f0000)
Jul 2 10:00:47 vnfsrv kernel: svc: svc_sock_detach(ffff8800159f0000)
Jul 2 10:00:47 vnfsrv kernel: svc: server ffff880016576000 waiting for data (to = 900000)
Jul 2 10:00:48 vnfsrv kernel: svc: socket ffff8800167aad40 TCP (listen) state change 10
Jul 2 10:00:48 vnfsrv kernel: svc: transport ffff8800159c0000 served by daemon ffff880016576000
Jul 2 10:00:48 vnfsrv kernel: svc: socket ffff880015a44d80 TCP (listen) state change 1
Jul 2 10:00:48 vnfsrv kernel: svc: tcp_accept ffff8800159c0000 sock ffff880016a2e840
Jul 2 10:00:48 vnfsrv kernel: nfsd: connect from 10.1.7.30, port=740
Jul 2 10:00:48 vnfsrv kernel: svc: svc_setup_socket ffff880016acc840
Jul 2 10:00:48 vnfsrv kernel: setting up TCP socket for reading
Jul 2 10:00:48 vnfsrv kernel: svc: svc_setup_socket created ffff8800152d7000 (inet ffff880015a44d80)
Jul 2 10:00:48 vnfsrv kernel: svc: transport ffff8800152d7000 served by daemon ffff8800167cc000
Jul 2 10:00:48 vnfsrv kernel: svc: server ffff8800167cc000, pool 0, transport ffff8800152d7000, inuse=3
Jul 2 10:00:48 vnfsrv kernel: svc: tcp_recv ffff8800152d7000 data 1 conn 0 close 0
Jul 2 10:00:48 vnfsrv kernel: svc: socket ffff8800152d7000 recvfrom(ffff8800152d72a4, 0) = 4
Jul 2 10:00:48 vnfsrv kernel: svc: TCP record, 200 bytes
Jul 2 10:00:48 vnfsrv kernel: svc: socket ffff8800152d7000 recvfrom(ffff88001607c0c8, 3896) = 200
Jul 2 10:00:48 vnfsrv kernel: svc: TCP final record (200 bytes)
Jul 2 10:00:48 vnfsrv kernel: svc: got len=200
Jul 2 10:00:48 vnfsrv kernel: svc: svc_authenticate (6)
Jul 2 10:00:48 vnfsrv kernel: svc: transport ffff8800159c0000 served by daemon ffff88001657a000
Jul 2 10:00:48 vnfsrv kernel: svc: tcp_accept ffff8800159c0000 sock ffff880016a2e840
Jul 2 10:00:48 vnfsrv kernel: svc: server ffff88001657a000 waiting for data (to = 900000)
Jul 2 10:00:48 vnfsrv kernel: svc: server ffff880016576000 waiting for data (to = 900000)
Jul 2 10:00:48 vnfsrv kernel: RPC: svcauth_gss: argv->iov_len = 172
Jul 2 10:00:48 vnfsrv kernel: RPC: gss_verify_mic_v2
Jul 2 10:00:48 vnfsrv kernel: RPC: gss_get_mic_v2
Jul 2 10:00:48 vnfsrv kernel: RPC: Want update, refage=120, age=62
Jul 2 10:00:53 vnfsrv kernel: svc: svc_process dropit
Jul 2 10:00:53 vnfsrv kernel: svc: xprt ffff8800152d7000 dropped request
Jul 2 10:00:53 vnfsrv kernel: svc: server ffff8800167cc000 waiting for data (to = 900000)
Jul 2 10:01:42 vnfsrv kernel: NFSD: laundromat service - starting
Jul 2 10:01:42 vnfsrv kernel: NFSD: laundromat_main - sleeping for 90 seconds
Jul 2 10:02:00 vnfsrv kernel: revisit canceled
Jul 2 10:02:00 vnfsrv kernel: svc: svc_sock_free(ffff8800159f0000)
Jul 2 10:02:00 vnfsrv kernel: revisit queued
Jul 2 10:02:00 vnfsrv kernel: svc: transport ffff8800152d7000 served by daemon ffff8800167cc000
Jul 2 10:02:00 vnfsrv kernel: svc: server ffff8800167cc000, pool 0, transport ffff8800152d7000, inuse=3
Jul 2 10:02:00 vnfsrv kernel: svc: got len=200
Jul 2 10:02:00 vnfsrv kernel: svc: transport ffff8800152d7000 served by daemon ffff880016576000
Jul 2 10:02:00 vnfsrv kernel: svc: server ffff880016576000, pool 0, transport ffff8800152d7000, inuse=5
Jul 2 10:02:00 vnfsrv kernel: svc: tcp_recv ffff8800152d7000 data 0 conn 0 close 0
Jul 2 10:02:00 vnfsrv kernel: svc: socket ffff8800152d7000 recvfrom(ffff8800152d72a0, 4) = -11
Jul 2 10:02:00 vnfsrv kernel: RPC: TCP recv_record got -11
Jul 2 10:02:00 vnfsrv kernel: svc: svc_authenticate (6)
Jul 2 10:02:00 vnfsrv kernel: RPC: svcauth_gss: argv->iov_len = 172
Jul 2 10:02:00 vnfsrv kernel: RPC: gss_get_mic_v2
Jul 2 10:02:00 vnfsrv kernel: RPC: TCP recvfrom got EAGAIN
Jul 2 10:02:00 vnfsrv kernel: svc: got len=0
Jul 2 10:02:00 vnfsrv kernel: svc: server ffff880016576000 waiting for data (to = 900000)
Jul 2 10:02:00 vnfsrv kernel: RPC: Want update, refage=120, age=0
Jul 2 10:02:05 vnfsrv kernel: svc: svc_process dropit
Jul 2 10:02:05 vnfsrv kernel: svc: xprt ffff8800152d7000 dropped request
Jul 2 10:02:05 vnfsrv kernel: svc: server ffff8800167cc000 waiting for data (to = 900000)
Jul 2 10:02:23 vnfsrv kernel: svc: socket ffff880015a44d80 TCP (connected) state change 8 (svsk ffff8800152d7000)
Jul 2 10:02:23 vnfsrv kernel: svc: transport ffff8800152d7000 served by daemon ffff8800167cc000
Jul 2 10:02:23 vnfsrv kernel: svc: socket ffff880015a44d80 TCP data ready (svsk ffff8800152d7000)
Jul 2 10:02:23 vnfsrv kernel: svc: transport ffff8800152d7000 busy, not enqueued
Jul 2 10:02:23 vnfsrv kernel: svc_recv: found XPT_CLOSE
Jul 2 10:02:23 vnfsrv kernel: svc: svc_delete_xprt(ffff8800152d7000)
Jul 2 10:02:23 vnfsrv kernel: svc: svc_tcp_sock_detach(ffff8800152d7000)
Jul 2 10:02:23 vnfsrv kernel: svc: svc_sock_detach(ffff8800152d7000)
Jul 2 10:02:23 vnfsrv kernel: svc: server ffff8800167cc000 waiting for data (to = 900000)
Jul 2 10:02:43 vnfsrv kernel: svc_age_temp_xprts
Regards
Sven
--
"Das ist halt der Unterschied: Unix ist ein Betriebssystem mit Tradition,
die anderen sind einfach von sich aus unlogisch."
(Anselm Lingnau in de.comp.os.unix.discussion)
/me ist giggls@ircnet, http://sven.gegg.us/ im WWW
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Kerberized NFS-Server Problem still present in 3.10.0-rc2
[not found] ` <20130705203435.GE8288@fieldses.org>
@ 2013-07-08 8:08 ` Sven Geggus
2013-07-08 13:35 ` J. Bruce Fields
2013-07-09 16:57 ` J. Bruce Fields
0 siblings, 2 replies; 19+ messages in thread
From: Sven Geggus @ 2013-07-08 8:08 UTC (permalink / raw)
To: J. Bruce Fields; +Cc: linux-nfs
[-- Attachment #1: Type: text/plain, Size: 1192 bytes --]
Monday Monday, so good to me :)
On Friday, 5. Jul 2013 22:34, J. Bruce Fields wrote:
> Hm, might be interesting to see what mountd's doing too:
>
> strace -p $(pidof rpc.svcgssd) -s4096 -e trace=open,close,read,write
OK, output attached. While reading this output I recogniced, that I
overlooked the following error-messages from rpc.svcgssd and rpc.mountd:
Jul 8 09:53:38 vnfsrv rpc.svcgssd[2914]: ERROR: GSS-API: error in gss_free_lucid_sec_context(): GSS_S_NO_CONTEXT (No context has been established) - Unknown error
Jul 8 09:53:38 vnfsrv rpc.svcgssd[2914]: WARN: failed to free lucid sec context
Jul 8 09:53:38 vnfsrv rpc.mountd[2927]: qword_eol: fprintf failed: errno 22 (Invalid argument)
> Hm, maybe this gid upcall? Does the following (probably not completely
> right) help?
Yes, we are getting there. While the strange messages from rpc.svcgssd
persist, the mount now seems to work again after your patch has been
applied.
Regards
Sven
--
"Remember, democracy never lasts long. It soon wastes itself,
exhausts and murders itself. There never was a democracy yet
that did not commit suicide." (John Quincy Adams)
/me is giggls@ircnet, http://sven.gegg.us/ on the Web
[-- Attachment #2: strace-output-rpc.svcgssd --]
[-- Type: text/plain, Size: 18563 bytes --]
read(4, "\\x \\x6082051f06092a864886f71201020201006e82050e3082050aa003020105a10302010ea20703050020000000a382040761820403308203ffa003020105a1101b0e50432e494954422e4648472e4445a2273025a003020103a11e301c1b036e66731b15766e667372762e70632e696974622e6668672e6465a38203bb308203b7a003020117a103020102a28203a9048203a5c0be536630d9eddaa21dcaa5c68959ddcb5da7ea2ea2dbf2e641bd866fc5c5d1c0c21e261366d40775d8e8cec0c403f73255555ff92a20b373a778819bb1fa891e9ccfd6622a683e5a3c466e731f5b884ed79ff25f44bbcf20b493753de50b0cb7b2dc25266427bf658db58a51daba1339897c4d6709bb8cf220384faa7203bf9a92cfa2391d10eb3cf58a31aed3921b23cf1e49e0b91b615b51fea8d2c10307eec97ae4c8b5a0305105f1e5532f5f38dfc3ba6bd1f9667a5abd83fda0efaea4b532a5962c01a46fe8306072d3bc6d62062b10e73c0efe03316b3f9b8181b67d87fbc62cb371755b888e941cbd105d47e92b69439a87c36e438e5a0ee64f832efb8b46f0c4c65222721a06bb29456a744df5fe56f6b91c2d947e7f41b15ed46dc73d19c5a11974cc50d5faa53ffd27014aba6b69adf28d8e9efa4630c595477246f2d1be456b9fa446b55ef4182dd5f0e1bd0f418ce1bca9181759e68424ca9c55c9a17e62ab19d84be413615f650bb0ba10d1fc938b81cda4623f113dbf74cab8254f5e7e3e6a16a86efb140c1abedc65176795067bf52bb3d273b0833859878e9b51894689d24080929b57763a507e7435effb351f6ac4f2658fd92ab51c6b2b0b234ff413cbaf05e150ad19b220a8d63244bc6ebf601bc3ed3e5f5665c35b4bcb5696f8b5bcaff5ea829cd1cadb8ad1de0010e36fb8bf10305b396614d7bc483e2318391278c3c104a8d49c52b0c64091f4771b9aa05a710273c0a9fc074577b0fd7ad076fb14ba7760c8a95ffa49e52c33520420304d90d1dbe1c7d4960ef19fec74dd1af6ec7da006ac0dbf7aea78520c7ee0a378e4ac1cbe84b40b6d7e6aa43a2dcdc059acd71292590993b403f10f54c9f003996fe58b135dd2a3c1e23c6c39414a7a06de39e1625e209c1f23004a413577bd4aa9456107158a2e44490aad8a6db67a0672eb7ae51e1b01c0bf4ce63cc5e4fdfeced6eb753f76f0940366c4c577ac6794030d8850f12c2052ee20fdbea7b0bcc10392d8bb96a114088787dc1183bfa9bb86f0cb5872a0087b9234015ccd9bc33ea7f415e3d4669197cc036e9cbc4849eb08e4e91e1d7c7515851c3e473ac1e92076f2b4ad549a99ca0c4b50431bc5f6e6693f3c5697f96168f91221e991f08b0820d795d24b9caf587d70916c0e1b90fd51c6e615631039c1e748a841e349eb6d5272216bd2eec53ad09826e12a701886c46656627a1379f48e8b79592c2fd424b2b29414dec3d11093f618af48fa912105fd163c9b76df3a6f5a2608629b27e25b7476cc80cff8d8fdd466d5ff7fa481e93081e6a003020117a281de0481db5d54a6ca5f33bcd5f204274dc255945eb2ee22e4657eeae001d53df27a8bbdaf247e598050e5e9957588aad75de62ec64aaf586aed86cc173ce41ff9a590d5ac5588166cb2904470731606da0e29a16174ef44dab40383ba76f849994653073b94c1b50463cfb9e24068e07d93effa65ebd95ebb33a812a412fc6367d71dbcba30f7e95365fd787c00e23c98f4fb10a8bfc292426bad83305778d58e43758cd4b5005672c494812521d29c355a03e5e046927b5aff8ff12d7d9f07e70a4d3e8b7859fe9d8ae56595a3e89cb289f4f720ec28fbe179a160afcb2b4b\n", 4096) = 2636
open("/proc/fs/nfsd/supported_krb5_enctypes", O_RDONLY) = 13
read(13, "18,17,16,23,3,1,2", 4096) = 17
read(13, "", 4096) = 0
close(13) = 0
open("/etc/krb5.conf", O_RDONLY) = 13
read(13, "[libdefaults]\n default_realm = PC.IITB.FHG.DE\n default_tkt_enctypes = arcfour-hmac-md5\n default_tgs_enctypes = arcfour-hmac-md5\n\t\n forwardable = true\n\n[realms]\n PC.IITB.FHG.DE = {\n kdc = pcdc1.pc.iitb.fhg.de\n kdc = pcdc2.pc.iitb.fhg.de\n }\n\n[domain_realm]\n pc.iitb.fhg.de = PC.IITB.FHG.DE\n .pc.iitb.fhg.de = PC.IITB.FHG.DE\n\n\n", 4096) = 338
read(13, "", 4096) = 0
close(13) = 0
open("/dev/urandom", O_RDONLY) = 13
read(13, "=\255\177\337\3\32\23\234\363\336\6\221\"7b\232\177\272\35\255\10\317e\226\330\257\1\2\271\33(\303\r\247^\1\233\234>\372\26.\210\207\255]X\365\225\357<7t\22\34\243yp\327\325UvZ\4", 64) = 64
close(13) = 0
open("/etc/krb5.conf", O_RDONLY) = 13
read(13, "[libdefaults]\n default_realm = PC.IITB.FHG.DE\n default_tkt_enctypes = arcfour-hmac-md5\n default_tgs_enctypes = arcfour-hmac-md5\n\t\n forwardable = true\n\n[realms]\n PC.IITB.FHG.DE = {\n kdc = pcdc1.pc.iitb.fhg.de\n kdc = pcdc2.pc.iitb.fhg.de\n }\n\n[domain_realm]\n pc.iitb.fhg.de = PC.IITB.FHG.DE\n .pc.iitb.fhg.de = PC.IITB.FHG.DE\n\n\n", 4096) = 338
read(13, "", 4096) = 0
close(13) = 0
open("/dev/urandom", O_RDONLY) = 13
read(13, "#\261\\\233\220\376I\227\27@\326c&\177\f\372 \371)B\1\237\302!\373\375\215\3502\316\325|71\320\275\275\340\237\375\353RAR\256\307\222\254'\207{&\265\36d\n6\244Y\36`C\246\345", 64) = 64
close(13) = 0
open("/etc/krb5.conf", O_RDONLY) = 13
read(13, "[libdefaults]\n default_realm = PC.IITB.FHG.DE\n default_tkt_enctypes = arcfour-hmac-md5\n default_tgs_enctypes = arcfour-hmac-md5\n\t\n forwardable = true\n\n[realms]\n PC.IITB.FHG.DE = {\n kdc = pcdc1.pc.iitb.fhg.de\n kdc = pcdc2.pc.iitb.fhg.de\n }\n\n[domain_realm]\n pc.iitb.fhg.de = PC.IITB.FHG.DE\n .pc.iitb.fhg.de = PC.IITB.FHG.DE\n\n\n", 4096) = 338
read(13, "", 4096) = 0
close(13) = 0
open("/dev/urandom", O_RDONLY) = 13
read(13, "\352\224\336\fM\36Ys\2319)\333\10\256Pa8S?\274\215x\10I\5\270u\225\21\206\370\314\343R\214\341\25eM\322\233\267\304cj\347\323dqH~\37\241?r\17\330\0j\226<o\262{", 64) = 64
close(13) = 0
open("/etc/krb5.conf", O_RDONLY) = 13
read(13, "[libdefaults]\n default_realm = PC.IITB.FHG.DE\n default_tkt_enctypes = arcfour-hmac-md5\n default_tgs_enctypes = arcfour-hmac-md5\n\t\n forwardable = true\n\n[realms]\n PC.IITB.FHG.DE = {\n kdc = pcdc1.pc.iitb.fhg.de\n kdc = pcdc2.pc.iitb.fhg.de\n }\n\n[domain_realm]\n pc.iitb.fhg.de = PC.IITB.FHG.DE\n .pc.iitb.fhg.de = PC.IITB.FHG.DE\n\n\n", 4096) = 338
read(13, "", 4096) = 0
close(13) = 0
open("/dev/urandom", O_RDONLY) = 13
read(13, "\362\0071\321\233\241\241\22\207[\363\352\314\327\2\273\265\1Q\36\215\205\355\255:\355\327\16\30\237\365\241\t\243}=\277O\220\v'P\202\254\36\203\212\317\26\311\360\377n\246\242\27\7\325\241\311\332\33V\257", 64) = 64
close(13) = 0
open("/etc/krb5.conf", O_RDONLY) = 13
read(13, "[libdefaults]\n default_realm = PC.IITB.FHG.DE\n default_tkt_enctypes = arcfour-hmac-md5\n default_tgs_enctypes = arcfour-hmac-md5\n\t\n forwardable = true\n\n[realms]\n PC.IITB.FHG.DE = {\n kdc = pcdc1.pc.iitb.fhg.de\n kdc = pcdc2.pc.iitb.fhg.de\n }\n\n[domain_realm]\n pc.iitb.fhg.de = PC.IITB.FHG.DE\n .pc.iitb.fhg.de = PC.IITB.FHG.DE\n\n\n", 4096) = 338
read(13, "", 4096) = 0
close(13) = 0
open("/dev/urandom", O_RDONLY) = 13
read(13, "Lp\354\0\375\202\232:c\360F\262\2\272\226\212\261\311|1b\241\322\250\365\257M\260\302O\276\316\24B)A\265e\342\235\234\254\32\246\311\2.n[\315\205\332[\354\244M\225\271n\317*l\207x", 64) = 64
close(13) = 0
open("/etc/krb5.conf", O_RDONLY) = 13
read(13, "[libdefaults]\n default_realm = PC.IITB.FHG.DE\n default_tkt_enctypes = arcfour-hmac-md5\n default_tgs_enctypes = arcfour-hmac-md5\n\t\n forwardable = true\n\n[realms]\n PC.IITB.FHG.DE = {\n kdc = pcdc1.pc.iitb.fhg.de\n kdc = pcdc2.pc.iitb.fhg.de\n }\n\n[domain_realm]\n pc.iitb.fhg.de = PC.IITB.FHG.DE\n .pc.iitb.fhg.de = PC.IITB.FHG.DE\n\n\n", 4096) = 338
read(13, "", 4096) = 0
close(13) = 0
open("/dev/urandom", O_RDONLY) = 13
read(13, "Y\375\23\321>\315pb(\2427f\350|\367\311\377WEg\v\1\272Ff`\224\364\273?9\370\245\202\271\213\216\311\240\27 \10;\375+U>\273\317\307u0[\303[YL\237\331\236\262\27\2031", 64) = 64
close(13) = 0
open("/etc/krb5.conf", O_RDONLY) = 13
read(13, "[libdefaults]\n default_realm = PC.IITB.FHG.DE\n default_tkt_enctypes = arcfour-hmac-md5\n default_tgs_enctypes = arcfour-hmac-md5\n\t\n forwardable = true\n\n[realms]\n PC.IITB.FHG.DE = {\n kdc = pcdc1.pc.iitb.fhg.de\n kdc = pcdc2.pc.iitb.fhg.de\n }\n\n[domain_realm]\n pc.iitb.fhg.de = PC.IITB.FHG.DE\n .pc.iitb.fhg.de = PC.IITB.FHG.DE\n\n\n", 4096) = 338
read(13, "", 4096) = 0
close(13) = 0
open("/dev/urandom", O_RDONLY) = 13
read(13, "\312F\336\211n_s\340\311\270\376=\212w\347\f\237\17E%\306\236t\5\2558\341\252c\250\366\4\356T\323\353\0\242A\24g\34\n\244ct<\17E\336\303\2328\341\301\274\3612v-X5\324)", 64) = 64
close(13) = 0
open("/etc/krb5.conf", O_RDONLY) = 13
read(13, "[libdefaults]\n default_realm = PC.IITB.FHG.DE\n default_tkt_enctypes = arcfour-hmac-md5\n default_tgs_enctypes = arcfour-hmac-md5\n\t\n forwardable = true\n\n[realms]\n PC.IITB.FHG.DE = {\n kdc = pcdc1.pc.iitb.fhg.de\n kdc = pcdc2.pc.iitb.fhg.de\n }\n\n[domain_realm]\n pc.iitb.fhg.de = PC.IITB.FHG.DE\n .pc.iitb.fhg.de = PC.IITB.FHG.DE\n\n\n", 4096) = 338
read(13, "", 4096) = 0
close(13) = 0
open("/dev/urandom", O_RDONLY) = 13
read(13, "\357OB\240\217 }_\304gQ\363Al\245\36Y\345\317\244iBu\n\271\266\1zj\350rfV\373\244\261\373jz\225[\226\367\1\340\27\331\352\213U\337\370\17ZWus\234!\337\272\372\341O", 64) = 64
close(13) = 0
open("/etc/krb5.conf", O_RDONLY) = 13
read(13, "[libdefaults]\n default_realm = PC.IITB.FHG.DE\n default_tkt_enctypes = arcfour-hmac-md5\n default_tgs_enctypes = arcfour-hmac-md5\n\t\n forwardable = true\n\n[realms]\n PC.IITB.FHG.DE = {\n kdc = pcdc1.pc.iitb.fhg.de\n kdc = pcdc2.pc.iitb.fhg.de\n }\n\n[domain_realm]\n pc.iitb.fhg.de = PC.IITB.FHG.DE\n .pc.iitb.fhg.de = PC.IITB.FHG.DE\n\n\n", 4096) = 338
read(13, "", 4096) = 0
close(13) = 0
open("/dev/urandom", O_RDONLY) = 13
read(13, "\224\341\263\4\305\264\266\327T\20\243g\343Q\32t\3CPA/_Jt\352O\205\376\225\330\365^]\214\242\214\212\200?s\315>\312W\7\373\0\343)b\244\230\250v\6\24265\324\317\21\26\346\212", 64) = 64
close(13) = 0
open("/dev/urandom", O_RDONLY) = 13
read(13, "\304\t\10Xm\320\304\273\371\327\333@\307\332\362\251j\246\356\347P\256\3238H\16\337\226\342\361\317\5\34\241\314W\205\333e\33@)n%z\2178\314\215\0374\204\0070Qd\v\374,\213z\360\212\376", 64) = 64
close(13) = 0
open("/etc/krb5.keytab", O_RDONLY) = 13
read(13, "\5\2\0\0\0D\0\2\0\16PC.IITB.FHG.DE\0\4host\0\25vnfsrv.pc.iitb.fhg.de\0\0\0\1Q\260nq\2\0\1\0\10\346\2177^\v\302\255\250\0\0\0D\0\2\0\16PC.IITB.FHG.DE\0\4host\0\25vnfsrv.pc.iitb.fhg.de\0\0\0\1Q\260nq\2\0\3\0\10\346\2177^\v\302\255\250\0\0\0L\0\2\0\16PC.IITB.FHG.DE\0\4host\0\25vnfsrv.pc.iitb.fhg.de\0\0\0\1Q\260nq\2\0\27\0\20\200\205\364\330\203\321\331]\36\16\0105'\242\377C\0\0\0005\0\2\0\16PC.IITB.FHG.DE\0\4host\0\6VNFSRV\0\0\0\1Q\260nq\2\0\1\0\10\346\2177^\v\302\255\250\0\0\0005\0\2\0\16PC.IITB.FHG.DE\0\4host\0\6VNFSRV\0\0\0\1Q\260nq\2\0\3\0\10\346\2177^\v\302\255\250\0\0\0=\0\2\0\16PC.IITB.FHG.DE\0\4host\0\6VNFSRV\0\0\0\1Q\260nq\2\0\27\0\20\200\205\364\330\203\321\331]\36\16\0105'\242\377C\0\0\0000\0\1\0\16PC.IITB.FHG.DE\0\7VNFSRV$\0\0\0\1Q\260nq\2\0\1\0\10\346\2177^\v\302\255\250\0\0\0000\0\1\0\16PC.IITB.FHG.DE\0\7VNFSRV$\0\0\0\1Q\260nq\2\0\3\0\10\346\2177^\v\302\255\250\0\0\0008\0\1\0\16PC.IITB.FHG.DE\0\7VNFSRV$\0\0\0\1Q\260nq\2\0\27\0\20\200\205\364\330\203\321\331]\36\16\0105'\242\377C\0\0\0C\0\2\0\16PC.IITB.FHG.DE\0\3nfs\0\25vnfsrv.pc.iitb.fhg.de\0\0\0\1Q\260n\231\2\0\1\0\10\346\2177^\v\302\255\250\0\0\0C\0\2\0\16PC.IITB.FHG.DE\0\3nfs\0\25vnfsrv.pc.iitb.fhg.de\0\0\0\1Q\260n\231\2\0\3\0\10\346\2177^\v\302\255\250\0\0\0K\0\2\0\16PC.IITB.FHG.DE\0\3nfs\0\25vnfsrv.pc.iitb.fhg.de\0\0\0\1Q\260n\231\2\0\27\0\20\200\205\364\330\203\321\331]\36\16\0105'\242\377C\0\0\0004\0\2\0\16PC.IITB.FHG.DE\0\3nfs\0\6VNFSRV\0\0\0\1Q\260n\231\2\0\1\0\10\346\2177^\v\302\255\250\0\0\0004\0\2\0\16PC.IITB.FHG.DE\0\3nfs\0\6VNFSRV\0\0\0\1Q\260n\232\2\0\3\0\10\346\2177^\v\302\255\250\0\0\0<\0\2\0\16PC.IITB.FHG.DE\0\3nfs\0\6VNFSRV\0\0\0\1Q\260n\232\2\0\27\0\20\200\205\364\330\203\321\331]\36\16\0105'\242\377C", 8192) = 966
close(13) = 0
write(3, "\1\0\0\0\0k\0\0\0HASH:1112FD81D4B188BCA77FFDC69D0C32FF 21:VENUS$@PC.IITB.FHG.DE 40:nfs/vnfsrv.pc.iitb.fhg.de@PC.IITB.FHG.DE\0\214#\1\0\274m\332Q\26\0\0\0VENUS$@PC.IITB.FHG.DE\0)\0\0\0nfs/vnfsrv.pc.iitb.fhg.de@PC.IITB.FHG.DE\0\214#\1\0\274m\332Q", 203) = 203
open("/usr/lib/x86_64-linux-gnu/krb5/plugins/authdata", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/usr/lib/x86_64-linux-gnu/krb5/plugins/authdata", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/dev/urandom", O_RDONLY) = 13
read(13, "w\253\244\312k\341q\342\251I:\33b34\322\210\32\213\246\225@\25\204\25?\t\344\321\0038\322$:|s\177\30$\232\21B\203\23\331\320\327\310\34W\24x\2520\2\355~\251_\376x\304\262\36", 64) = 64
close(13) = 0
open("/dev/urandom", O_RDONLY) = 13
read(13, "*xH\\0b|J\265\276\233o\253\320\352\212\364;\263\214\376#\n\16\254\363Qp\371\342.\370>\2348W\325\276xF\345q\21\334v\255\244\232d:\237\366~\313\360h\210A\4s\314,\365\201", 64) = 64
close(13) = 0
open("/dev/urandom", O_RDONLY) = 13
read(13, "!\237\364Z\310\305\221)\201[\313\253\277R\276P1\273\304\23\31\222T\266\2635(\2775\213\312\342\300M\272_\21\211x\301_HD\242\314bW\315A\200\25VQ\2113\340\233\n\5\3062\335T_", 64) = 64
close(13) = 0
open("/dev/urandom", O_RDONLY) = 13
read(13, "\333-)\377\31^\347_\311\307\300\257\254\211\221\361}\251\371 \346\253\363J\267\33-\24\316\331=\250\233S\277\326h\0229l\355\242-\310\3630\v\4]\315\22\222\2454z\312\32\\\r\3t\312\2\f", 64) = 64
close(13) = 0
write(2, "rpc.svcgssd: ", 13) = 13
write(2, "ERROR: GSS-API: error in gss_free_lucid_sec_context(): GSS_S_NO_CONTEXT (No context has been established) - Unknown error\n", 122) = 122
write(2, "\n", 1) = 1
write(2, "rpc.svcgssd: ", 13) = 13
write(2, "WARN: failed to free lucid sec context\n", 39) = 39
write(2, "\n", 1) = 1
open("/proc/net/rpc/auth.rpcsec.context/channel", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 13
write(13, "\\x02000000 1373304166 -1 -1 0 krb5 \\x0600000066f5da51fe3cc615000000001200000078e144e1ed0b6788fa4c4482792932f76ebdf8af531067a24badeb53eba8d9bd \n", 143) = 143
close(13) = 0
open("/proc/net/rpc/auth.rpcsec.init/channel", O_WRONLY) = 13
write(13, "\\x \\x6082051f06092a864886f71201020201006e82050e3082050aa003020105a10302010ea20703050020000000a382040761820403308203ffa003020105a1101b0e50432e494954422e4648472e4445a2273025a003020103a11e301c1b036e66731b15766e667372762e70632e696974622e6668672e6465a38203bb308203b7a003020117a103020102a28203a9048203a5c0be536630d9eddaa21dcaa5c68959ddcb5da7ea2ea2dbf2e641bd866fc5c5d1c0c21e261366d40775d8e8cec0c403f73255555ff92a20b373a778819bb1fa891e9ccfd6622a683e5a3c466e731f5b884ed79ff25f44bbcf20b493753de50b0cb7b2dc25266427bf658db58a51daba1339897c4d6709bb8cf220384faa7203bf9a92cfa2391d10eb3cf58a31aed3921b23cf1e49e0b91b615b51fea8d2c10307eec97ae4c8b5a0305105f1e5532f5f38dfc3ba6bd1f9667a5abd83fda0efaea4b532a5962c01a46fe8306072d3bc6d62062b10e73c0efe03316b3f9b8181b67d87fbc62cb371755b888e941cbd105d47e92b69439a87c36e438e5a0ee64f832efb8b46f0c4c65222721a06bb29456a744df5fe56f6b91c2d947e7f41b15ed46dc73d19c5a11974cc50d5faa53ffd27014aba6b69adf28d8e9efa4630c595477246f2d1be456b9fa446b55ef4182dd5f0e1bd0f418ce1bca9181759e68424ca9c55c9a17e62ab19d84be413615f650bb0ba10d1fc938b81cda4623f113dbf74cab8254f5e7e3e6a16a86efb140c1abedc65176795067bf52bb3d273b0833859878e9b51894689d24080929b57763a507e7435effb351f6ac4f2658fd92ab51c6b2b0b234ff413cbaf05e150ad19b220a8d63244bc6ebf601bc3ed3e5f5665c35b4bcb5696f8b5bcaff5ea829cd1cadb8ad1de0010e36fb8bf10305b396614d7bc483e2318391278c3c104a8d49c52b0c64091f4771b9aa05a710273c0a9fc074577b0fd7ad076fb14ba7760c8a95ffa49e52c33520420304d90d1dbe1c7d4960ef19fec74dd1af6ec7da006ac0dbf7aea78520c7ee0a378e4ac1cbe84b40b6d7e6aa43a2dcdc059acd71292590993b403f10f54c9f003996fe58b135dd2a3c1e23c6c39414a7a06de39e1625e209c1f23004a413577bd4aa9456107158a2e44490aad8a6db67a0672eb7ae51e1b01c0bf4ce63cc5e4fdfeced6eb753f76f0940366c4c577ac6794030d8850f12c2052ee20fdbea7b0bcc10392d8bb96a114088787dc1183bfa9bb86f0cb5872a0087b9234015ccd9bc33ea7f415e3d4669197cc036e9cbc4849eb08e4e91e1d7c7515851c3e473ac1e92076f2b4ad549a99ca0c4b50431bc5f6e6693f3c5697f96168f91221e991f08b0820d795d24b9caf587d70916c0e1b90fd51c6e615631039c1e748a841e349eb6d5272216bd2eec53ad09826e12a701886c46656627a1379f48e8b79592c2fd424b2b29414dec3d11093f618af48fa912105fd163c9b76df3a6f5a2608629b27e25b7476cc80cff8d8fdd466d5ff7fa481e93081e6a003020117a281de0481db5d54a6ca5f33bcd5f204274dc255945eb2ee22e4657eeae001d53df27a8bbdaf247e598050e5e9957588aad75de62ec64aaf586aed86cc173ce41ff9a590d5ac5588166cb2904470731606da0e29a16174ef44dab40383ba76f849994653073b94c1b50463cfb9e24068e07d93effa65ebd95ebb33a812a412fc6367d71dbcba30f7e95365fd787c00e23c98f4fb10a8bfc292426bad83305778d58e43758cd4b5005672c494812521d29c355a03e5e046927b5aff8ff12d7d9f07e70a4d3e8b7859fe9d8ae56595a3e89cb289f4f720ec28fbe179a160afcb2b4b 1373269499 0 0 \\x02000000 \\x60819506092a864886f71201020202006f8185308182a003020105a10302010fa2763074a003020117a26d046b60bea13089ec0fa390c0936703f608842069597bfeff00469419cdb6aab8b3e02ad15174806fe84012f2dc84cbd5304bbde04675c75eae472674609cf97a75a7a96306123387c70be8993a170c31c5f6ef6850d4905121272725e6ad523a10fd2f7ed0f5c76c4535f41421 \n", 2970) = 2970
close(13) = 0
open("/etc/krb5.conf", O_RDONLY) = 13
read(13, "[libdefaults]\n default_realm = PC.IITB.FHG.DE\n default_tkt_enctypes = arcfour-hmac-md5\n default_tgs_enctypes = arcfour-hmac-md5\n\t\n forwardable = true\n\n[realms]\n PC.IITB.FHG.DE = {\n kdc = pcdc1.pc.iitb.fhg.de\n kdc = pcdc2.pc.iitb.fhg.de\n }\n\n[domain_realm]\n pc.iitb.fhg.de = PC.IITB.FHG.DE\n .pc.iitb.fhg.de = PC.IITB.FHG.DE\n\n\n", 4096) = 338
read(13, "", 4096) = 0
close(13) = 0
open("/dev/urandom", O_RDONLY) = 13
read(13, "\347Y\373\4\247\233\30m\346\257\237\222\313\3318\35fJ\241\37I\350\374\366\276\333\2214\375\371l(\344\6\274\362\221\205U\213}\266\325\n;[\267\255X\360ogO6\24\247\30\242\333\322$\31;!", 64) = 64
close(13) = 0
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Kerberized NFS-Server Problem still present in 3.10.0-rc2
2013-07-08 8:08 ` Sven Geggus
@ 2013-07-08 13:35 ` J. Bruce Fields
2013-07-08 15:54 ` Sven Geggus
2013-07-09 16:57 ` J. Bruce Fields
1 sibling, 1 reply; 19+ messages in thread
From: J. Bruce Fields @ 2013-07-08 13:35 UTC (permalink / raw)
To: Sven Geggus; +Cc: linux-nfs
On Mon, Jul 08, 2013 at 10:08:05AM +0200, Sven Geggus wrote:
> Monday Monday, so good to me :)
>
> On Friday, 5. Jul 2013 22:34, J. Bruce Fields wrote:
>
> > Hm, might be interesting to see what mountd's doing too:
> >
> > strace -p $(pidof rpc.svcgssd) -s4096 -e trace=open,close,read,write
Argh--I said "mountd", then I forgot to replace the rpc.svcgssd in the
cut-n-pasted commandline; should have been:
strace -p $(pidof rpc.mountd) -s4096 -e trace=open,close,read,write
>
> OK, output attached. While reading this output I recogniced, that I
> overlooked the following error-messages from rpc.svcgssd and rpc.mountd:
>
> Jul 8 09:53:38 vnfsrv rpc.svcgssd[2914]: ERROR: GSS-API: error in gss_free_lucid_sec_context(): GSS_S_NO_CONTEXT (No context has been established) - Unknown error
> Jul 8 09:53:38 vnfsrv rpc.svcgssd[2914]: WARN: failed to free lucid sec context
> Jul 8 09:53:38 vnfsrv rpc.mountd[2927]: qword_eol: fprintf failed: errno 22 (Invalid argument)
>
> > Hm, maybe this gid upcall? Does the following (probably not completely
> > right) help?
>
> Yes, we are getting there. While the strange messages from rpc.svcgssd
> persist, the mount now seems to work again after your patch has been
> applied.
Anyway. OK, that more or less solves the mystery, though the strace
output might still be interesting.
--b.
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Kerberized NFS-Server Problem still present in 3.10.0-rc2
2013-07-08 13:35 ` J. Bruce Fields
@ 2013-07-08 15:54 ` Sven Geggus
2013-07-08 19:41 ` J. Bruce Fields
0 siblings, 1 reply; 19+ messages in thread
From: Sven Geggus @ 2013-07-08 15:54 UTC (permalink / raw)
To: J. Bruce Fields; +Cc: linux-nfs
J. Bruce Fields schrieb am Montag, den 08. Juli um 15:35 Uhr:
> Anyway. OK, that more or less solves the mystery, though the strace
> output might still be interesting.
Not very enlightening, at least for me, but here we go:
read(3, "nfsd 10.1.7.30\n", 2048) = 15
close(13) = 0
open("/var/lib/nfs/etab", O_RDONLY) = 13
close(13) = 0
close(13) = 0
write(3, "nfsd 10.1.7.30 1373300439 * \n", 29) = 29
read(4, "4294967295\n", 2048) = 11
close(14) = 0
close(13) = 0
read(13, "\2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\377\377\377\377\377\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0", 36) = 36
close(13) = 0
write(4, "4294967295 1373300439 0 \n", 25) = -1 EINVAL (Invalid argument)
Regards
Sven
--
The source code is not comprehensible
(found in bug section of man 8 telnetd on Redhat Linux)
/me is giggls@ircnet, http://sven.gegg.us/ on the Web
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Kerberized NFS-Server Problem still present in 3.10.0-rc2
2013-07-08 15:54 ` Sven Geggus
@ 2013-07-08 19:41 ` J. Bruce Fields
2013-07-09 16:03 ` Sven Geggus
0 siblings, 1 reply; 19+ messages in thread
From: J. Bruce Fields @ 2013-07-08 19:41 UTC (permalink / raw)
To: Sven Geggus; +Cc: linux-nfs
On Mon, Jul 08, 2013 at 05:54:06PM +0200, Sven Geggus wrote:
> J. Bruce Fields schrieb am Montag, den 08. Juli um 15:35 Uhr:
>
> > Anyway. OK, that more or less solves the mystery, though the strace
> > output might still be interesting.
>
> Not very enlightening, at least for me, but here we go:
>
> read(3, "nfsd 10.1.7.30\n", 2048) = 15
> close(13) = 0
> open("/var/lib/nfs/etab", O_RDONLY) = 13
> close(13) = 0
> close(13) = 0
> write(3, "nfsd 10.1.7.30 1373300439 * \n", 29) = 29
> read(4, "4294967295\n", 2048) = 11
> close(14) = 0
> close(13) = 0
> read(13, "\2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\377\377\377\377\377\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0", 36) = 36
> close(13) = 0
> write(4, "4294967295 1373300439 0 \n", 25) = -1 EINVAL (Invalid argument)
Thanks! Yep, 4294967295 is (u32)(-1), so it's this uid_valid check in
unix_gid_parse that we're hitting.
I'm not even sure whether it makes sense to be doing this upcall to ask
for supplemental groups in the -1 case. Going with the minimal fix for
now.
Oh, and oops, it should go to stable to--adding that Cc: to my local
copy of the patch.
--b.
commit 8efb88340e29293e05f6b498b60596884c05a8a8
Author: J. Bruce Fields <bfields@redhat.com>
Date: Mon Jul 8 13:44:45 2013 -0400
svcrpc: fix failures to handle -1 uid's
As of f025adf191924e3a75ce80e130afcd2485b53bb8 "sunrpc: Properly decode
kuids and kgids in RPC_AUTH_UNIX credentials" any rpc containing a -1
(0xffff) uid or gid would fail with a badcred error.
Commit afe3c3fd5392b2f0066930abc5dbd3f4b14a0f13 "svcrpc: fix failures to
handle -1 uid's and gid's" fixed part of the problem, but overlooked the
gid upcall--the kernel can request supplementary gid's for the -1 uid,
but mountd's attempt write a response will get -EINVAL.
Symptoms were nfsd failing to reply to the first attempt to use a newly
negotiated krb5 context.
Reported-by: Sven Geggus <lists@fuchsschwanzdomain.de>
Tested-by: Sven Geggus <lists@fuchsschwanzdomain.de>
Signed-off-by: J. Bruce Fields <bfields@redhat.com>
diff --git a/net/sunrpc/svcauth_unix.c b/net/sunrpc/svcauth_unix.c
index a98853d..621ca7b 100644
--- a/net/sunrpc/svcauth_unix.c
+++ b/net/sunrpc/svcauth_unix.c
@@ -493,8 +493,6 @@ static int unix_gid_parse(struct cache_detail *cd,
if (rv)
return -EINVAL;
uid = make_kuid(&init_user_ns, id);
- if (!uid_valid(uid))
- return -EINVAL;
ug.uid = uid;
expiry = get_expiry(&mesg);
^ permalink raw reply related [flat|nested] 19+ messages in thread
* Re: Kerberized NFS-Server Problem still present in 3.10.0-rc2
2013-07-08 19:41 ` J. Bruce Fields
@ 2013-07-09 16:03 ` Sven Geggus
0 siblings, 0 replies; 19+ messages in thread
From: Sven Geggus @ 2013-07-09 16:03 UTC (permalink / raw)
To: J. Bruce Fields
J. Bruce Fields schrieb am Montag, den 08. Juli um 21:41 Uhr:
> I'm not even sure whether it makes sense to be doing this upcall to ask
> for supplemental groups in the -1 case. Going with the minimal fix for
> now.
Confirmed to work fine here, but strange messages from userland rpc.svcgssd persist:
Jul 9 17:59:27 vnfsrv rpc.svcgssd[2919]: ERROR: GSS-API: error in gss_free_lucid_sec_context(): GSS_S_NO_CONTEXT (No context has been established) - Unknown error
Jul 9 17:59:27 vnfsrv rpc.svcgssd[2919]: WARN: failed to free lucid sec context
Jul 9 17:59:27 vnfsrv rpc.svcgssd[2919]: ERROR: GSS-API: error in gss_free_lucid_sec_context(): GSS_S_NO_CONTEXT (No context has been established) - Unknown error
Jul 9 17:59:27 vnfsrv rpc.svcgssd[2919]: WARN: failed to free lucid sec context
Jul 9 17:59:27 vnfsrv rpc.svcgssd[2919]: ERROR: GSS-API: error in gss_free_lucid_sec_context(): GSS_S_NO_CONTEXT (No context has been established) - Unknown error
Jul 9 17:59:27 vnfsrv rpc.svcgssd[2919]: WARN: failed to free lucid sec context
Jul 9 17:59:27 vnfsrv rpc.svcgssd[2919]: ERROR: GSS-API: error in gss_free_lucid_sec_context(): GSS_S_NO_CONTEXT (No context has been established) - Unknown error
Jul 9 17:59:27 vnfsrv rpc.svcgssd[2919]: WARN: failed to free lucid sec context
Jul 9 17:59:27 vnfsrv rpc.svcgssd[2919]: ERROR: GSS-API: error in gss_free_lucid_sec_context(): GSS_S_NO_CONTEXT (No context has been established) - Unknown error
Jul 9 17:59:27 vnfsrv rpc.svcgssd[2919]: WARN: failed to free lucid sec context
Jul 9 17:59:27 vnfsrv rpc.svcgssd[2919]: ERROR: GSS-API: error in gss_free_lucid_sec_context(): GSS_S_NO_CONTEXT (No context has been established) - Unknown error
Jul 9 17:59:27 vnfsrv rpc.svcgssd[2919]: WARN: failed to free lucid sec context
> commit 8efb88340e29293e05f6b498b60596884c05a8a8
OK, is this supposed to get into 3.9.x and 3.10.x respectively?
Regards
Sven
Microsoft ist offenbar die einzige Firma, die in der Lage ist, ein mit
Office nicht kompatibles Bürosoftwarepaket einzuführen.
(Florian Weimer in de.alt.sysadmin.recovery)
/me is giggls@ircnet, http://sven.gegg.us/ on the Web
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Kerberized NFS-Server Problem still present in 3.10.0-rc2
2013-07-08 8:08 ` Sven Geggus
2013-07-08 13:35 ` J. Bruce Fields
@ 2013-07-09 16:57 ` J. Bruce Fields
2013-07-09 17:23 ` Chuck Lever
2013-07-10 7:55 ` Sven Geggus
1 sibling, 2 replies; 19+ messages in thread
From: J. Bruce Fields @ 2013-07-09 16:57 UTC (permalink / raw)
To: Sven Geggus; +Cc: linux-nfs, Chuck Lever, NeilBrown
On Mon, Jul 08, 2013 at 10:08:05AM +0200, Sven Geggus wrote:
> OK, output attached. While reading this output I recogniced, that I
> overlooked the following error-messages from rpc.svcgssd and rpc.mountd:
I don't think they're causing you any practical problem, but there was
some discussion of how to destroy contexts in gssd recently that I
didn't follow closely enough. I seem to recall Neil and Chuck being the
ones chasing down those bugs?
> Jul 8 09:53:38 vnfsrv rpc.svcgssd[2914]: ERROR: GSS-API: error in gss_free_lucid_sec_context(): GSS_S_NO_CONTEXT (No context has been established) - Unknown error
> Jul 8 09:53:38 vnfsrv rpc.svcgssd[2914]: WARN: failed to free lucid sec context
Does rpc.svcgssd still need fixing? (Sven, could you remind us what
nfs-utils version this is from?)
--b.
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Kerberized NFS-Server Problem still present in 3.10.0-rc2
2013-07-09 16:57 ` J. Bruce Fields
@ 2013-07-09 17:23 ` Chuck Lever
2013-07-10 7:55 ` Sven Geggus
1 sibling, 0 replies; 19+ messages in thread
From: Chuck Lever @ 2013-07-09 17:23 UTC (permalink / raw)
To: J. Bruce Fields; +Cc: Sven Geggus, linux-nfs, NeilBrown
On Jul 9, 2013, at 12:57 PM, "J. Bruce Fields" <bfields@fieldses.org> wrote:
> On Mon, Jul 08, 2013 at 10:08:05AM +0200, Sven Geggus wrote:
>> OK, output attached. While reading this output I recogniced, that I
>> overlooked the following error-messages from rpc.svcgssd and rpc.mountd:
>
> I don't think they're causing you any practical problem, but there was
> some discussion of how to destroy contexts in gssd recently that I
> didn't follow closely enough. I seem to recall Neil and Chuck being the
> ones chasing down those bugs?
I haven't touched rpc.svcgssd. I thought this code was being replaced by the gss_proxy-based implementation.
>> Jul 8 09:53:38 vnfsrv rpc.svcgssd[2914]: ERROR: GSS-API: error in gss_free_lucid_sec_context(): GSS_S_NO_CONTEXT (No context has been established) - Unknown error
>> Jul 8 09:53:38 vnfsrv rpc.svcgssd[2914]: WARN: failed to free lucid sec context
>
> Does rpc.svcgssd still need fixing? (Sven, could you remind us what
> nfs-utils version this is from?)
>
> --b.
--
Chuck Lever
chuck[dot]lever[at]oracle[dot]com
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Kerberized NFS-Server Problem still present in 3.10.0-rc2
2013-07-09 16:57 ` J. Bruce Fields
2013-07-09 17:23 ` Chuck Lever
@ 2013-07-10 7:55 ` Sven Geggus
1 sibling, 0 replies; 19+ messages in thread
From: Sven Geggus @ 2013-07-10 7:55 UTC (permalink / raw)
To: linux-nfs
J. Bruce Fields <bfields@fieldses.org> wrote:
>> Jul 8 09:53:38 vnfsrv rpc.svcgssd[2914]: ERROR: GSS-API: error in gss_free_lucid_sec_context(): GSS_S_NO_CONTEXT (No context has been established) - Unknown error
>> Jul 8 09:53:38 vnfsrv rpc.svcgssd[2914]: WARN: failed to free lucid sec context
>
> Does rpc.svcgssd still need fixing? (Sven, could you remind us what
> nfs-utils version this is from?)
1.2.8
Regards
Sven
--
"Thinking of using NT for your critical apps?
Isn't there enough suffering in the world?"
(Advertisement of Sun Microsystems in Wall Street Journal)
/me is giggls@ircnet, http://sven.gegg.us/ on the Web
^ permalink raw reply [flat|nested] 19+ messages in thread
end of thread, other threads:[~2013-07-10 7:55 UTC | newest]
Thread overview: 19+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2013-06-19 13:47 Kerberized NFS-Server Problem still present in 3.10.0-rc2 Sven Geggus
2013-06-19 21:34 ` J. Bruce Fields
2013-06-20 8:03 ` Sven Geggus
2013-06-20 12:09 ` Sven Geggus
2013-06-20 14:49 ` J. Bruce Fields
2013-06-20 14:52 ` J. Bruce Fields
2013-06-21 8:32 ` Sven Geggus
2013-06-24 21:54 ` J. Bruce Fields
2013-06-25 9:46 ` Sven Geggus
2013-07-01 12:09 ` Sven Geggus
[not found] ` <20130701205234.GF19945@fieldses.org>
2013-07-02 8:05 ` Sven Geggus
[not found] ` <20130705181859.GA8288@fieldses.org>
[not found] ` <20130705203435.GE8288@fieldses.org>
2013-07-08 8:08 ` Sven Geggus
2013-07-08 13:35 ` J. Bruce Fields
2013-07-08 15:54 ` Sven Geggus
2013-07-08 19:41 ` J. Bruce Fields
2013-07-09 16:03 ` Sven Geggus
2013-07-09 16:57 ` J. Bruce Fields
2013-07-09 17:23 ` Chuck Lever
2013-07-10 7:55 ` Sven Geggus
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.