Bug 227726
Summary: | Oops in svcauth_gss_release and tcp_sendpage | ||
---|---|---|---|
Product: | Red Hat Enterprise Linux 4 | Reporter: | Jeff Layton <jlayton> |
Component: | kernel | Assignee: | Jeff Layton <jlayton> |
Status: | CLOSED ERRATA | QA Contact: | Brian Brock <bbrock> |
Severity: | medium | Docs Contact: | |
Priority: | medium | ||
Version: | 4.4 | CC: | staubach, steved |
Target Milestone: | --- | ||
Target Release: | --- | ||
Hardware: | All | ||
OS: | Linux | ||
Whiteboard: | |||
Fixed In Version: | RHBA-2007-0791 | Doc Type: | Bug Fix |
Doc Text: | Story Points: | --- | |
Clone Of: | Environment: | ||
Last Closed: | 2007-11-15 16:19:45 UTC | Type: | --- |
Regression: | --- | Mount Type: | --- |
Documentation: | --- | CRM: | |
Verified Versions: | Category: | --- | |
oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |
Cloudforms Team: | --- | Target Upstream Version: | |
Embargoed: | |||
Attachments: |
Description
Jeff Layton
2007-02-07 19:34:39 UTC
This problem also seems to exist on recent upstream kernels so it's probably also a problem on FC-6/RHEL-5. Finally got a chance to start looking at this again. Mounted a fc7 rawhide server (2.6.20-2925.5.fc7xen) on a RHEL4 client: host:/export on /mnt/krb5i type nfs (rw,sec=krb5i,addr=xxx.yyy.xxx.yyy) When I do simple operations in the filesystem (ls, etc), I get messages like this: RPC request reserved 164 but used 208 RPC request reserved 164 but used 208 RPC request reserved 172 but used 216 RPC request reserved 164 but used 208 RPC request reserved 172 but used 216 RPC request reserved 164 but used 208 These all seem to be 44 bytes more than they should be. Not yet sure of the significance of 44 bytes here. Had a look on the wire at what's happening at the time when these messages pop up: This message: RPC request reserved 164 but used 208 ...seems to correspond to a GETATTR call. On the wire, the GETATTR packets are 274 bytes total, and the RPC+NFS payload is 208 bytes. This one: RPC request reserved 172 but used 216 ...comes from an ACCESS call. On the wire, this is 282 bytes total, and the RPC+NFS payload is 216 bytes. So the kernel seems to be consistently underestimating the actual rq_reserved size that we need when using krb5i with nfs3. This code is pretty complex though, so still tracking down the actual cause... In comparing the same ACCESS packet in a krb5 vs. a krb5i mount, the size difference is actually in the NFS section of the packet (as decoded by wireshark). The RPC sections of both are the exact same size (68 bytes). The main differences seem to be that the krb5i packet has an extra 8 bytes at the beginning of the NFS section: 4 bytes for GSS Data Length 4 bytes for GSS Sequence Number This part seems to be accounted for in the iov_len passed to svc_reserve. The part that's not accounted for is the 44 byte (!) GSS Checksum at the very end of the packet. I think that's the likely problem here... At least one issue seems to be that after writing out the first part of the response header, svc_process() calls this: /* un-reserve some of the out-queue now that we have a * better idea of reply size */ if (procp->pc_xdrressize) svc_reserve(rqstp, procp->pc_xdrressize<<2); ...but, this does not take into account the size of the checksum at the end of the response. This is probably also a problem for krb5p. We don't seem to see this issue with NFSv4, but my guess is that's because the "reserved" size for a compound packet is likely large enough to encompass this in most cases. I did a quick hack to add 44 bytes to the end of the second argument in the call above, and that got rid of most of these errors. I still see some, so apparently there's another related issue someplace... The other related issue is the svc_reserve calls in nfsd/nfs3proc.c and nfsd/nfsproc.c, when I add 44 bytes to the "space" arg in those calls, then the errors go away completely. My thinking at this point is to add a wrapper of some sort for svc_reserve that adds an appropriate amount for the checksum in this situation, and call that wrapper instead of svc_reserve in these 3 places. This request was evaluated by Red Hat Product Management for inclusion in a Red Hat Enterprise Linux maintenance release. Product Management has requested further review of this request by Red Hat Engineering, for potential inclusion in a Red Hat Enterprise Linux Update release for currently deployed products. This request is not yet committed for inclusion in an Update release. The wrapper seems to have taken care of the extra printk's but I'm still getting near-immediate panics when I have a RHEL4 box act as a krb5i/nfs3 server. I still need to test with Neil Brown's patch to remove the BUG in svcauth_gss_release, but I'm thinking there's more than one problem at play here. I may split this up into multiple BZ's Finally NeilB mentioned that the second panic here may be related to this: http://bugzilla.kernel.org/show_bug.cgi?id=7795 ...but he wasn't sure. I need to look into that as well... Looking at a core from a panic with this stack trace (similar to the second one in comment #1): #5 [ffffff801c32bc40] error_exit at ffffffff8010ddc3 [exception RIP: tcp_sendpage+905] RIP: ffffffff8025a876 RSP: ffffff801c32bcf8 RFLAGS: 00010246 RAX: 0000000000000000 RBX: ffffff801d2be500 RCX: 0000000000000000 RDX: 0000000000000002 RSI: 00000000000005dc RDI: 00000000000005a8 RBP: 000000000000002c R8: 0000000000000000 R9: ffffffff8035b580 R10: ffffff801d2be500 R11: 00000000000000e4 R12: ffffff801b224100 R13: 0000000000000002 R14: ffffff801b224430 R15: 0000000000000000 ORIG_RAX: ffffffffffffffff CS: e030 SS: e02b #6 [ffffff801c32bcf0] tcp_sendpage at ffffffff8025a5ac #7 [ffffff801c32bd80] svc_sendto at ffffffffa00a6e00 #8 [ffffff801c32be40] svc_tcp_sendto at ffffffffa00a763e #9 [ffffff801c32be60] svc_send at ffffffffa00a7c9e #10 [ffffff801c32be90] svc_process at ffffffffa00a64d8 #11 [ffffff801c32bef0] nfsd at ffffffffa015b534 #12 [ffffff801c32bf50] kernel_thread at ffffffff8010e092 I *think* we're crashing in do_tcp_sendpages, at the get_page() call here: if (can_coalesce) { skb_shinfo(skb)->frags[i - 1].size += copy; } else { get_page(page); skb_fill_page_desc(skb, i, page, offset, copy); } get_page is an inline the just increments the counter in the page, so it does seem like page is likely NULL here. The box seems to crash pretty consistently in this spot. When I add the "don't assume page data when there is tail data" patch, this crashes on the mount, whereas without that, it doesn't crash until the first access. So that seems to change the behavior somehow. Created attachment 154924 [details]
patch -- don't assume that when xdr_buf has tail data that it also has page data
Tried this patch out and it actually seems to make the kernel crash sooner (on
the mount rather than on first access), so I think we are dealing with a NULL
payload or something along those lines...
Made some progress here. The issue (at least sometimes) seems to be that we have a non zero tail[0].iov_len but a NULL page for the tail. I added this small patch for debugging and it fired when the bug fired: --- a/net/sunrpc/svcsock.c +++ b/net/sunrpc/svcsock.c @@ -414,6 +418,8 @@ svc_sendto(struct svc_rqst *rqstp, struct xdr_buf *xdr) } /* send tail */ if (xdr->tail[0].iov_len) { + if (rqstp->rq_respages[rqstp->rq_restailpage] == NULL) + printk("%s: rqstp->rq_respages[rqstp->rq_restailpage]==NULL\n", __func__); result = sock->ops->sendpage(sock, rqstp->rq_respages[rqstp->rq_restailpage], ((unsigned long)xdr->tail[0].iov_base)& (PAGE_SIZE-1), xdr->tail[0].iov_len, 0); So it seems like bad tail section handling is the issue... Got this just before the second svc_send in svc_process. This would seem to indicate that the tail length is 44 bytes (!), but the tail page is NULL. svc_process: 2 tail[0].iov_len=44, rqstp->rq_respages[rqstp->rq_restailpage] == NULL Created attachment 155819 [details]
patch -- set tail[0].iov_base to NULL in svc_process
This patch seems to fix it. This went upstream as part of the patch to add
krb5p to the kernel, but seems to be necessary to make sure that krb5i works as
well.
Without this what's happening is that we should be hitting this condition in
svcauth_gss_release, but we're not:
if (resbuf->tail[0].iov_base == NULL) {
...so we end up assuming that we have a page for the response tail when we
actually don't.
I need to do a bunch more testing with this, and I think we also will want to
incorporate a couple of other patches that seem important here, but this seems
to be the root cause of most of the panics.
Created attachment 155826 [details]
patch -- combine several gssapi fixes
This is the patch I'm currently testing. It contains the one-line patch posted
earlier (which is part of the addition of rpcsec_gss privacy). That piece comes
from:
commit 7c9fdcfb1b64c47ed618c103b617af3f86e1239c
I also rolled in this patch since it looks like it could prevent a possible
bug:
commit dfee55f06213a23b250ea63ba41caa461cdd5e72
Author: NeilBrown <neilb>
Date: Mon Apr 10 22:55:34 2006 -0700
[PATCH] knfsd: svcrpc: gss: don't call svc_take_page unnecessarily
...and this one that removes the bogus BUG_ON() that I hit at connectathon
while testing this...
commit 153e44d22fb5f98198f90fbf56e89b345e48534d
Author: NeilBrown <neilb>
Date: Wed May 9 02:34:52 2007 -0700
knfsd: rpc: fix server-side wrapping of krb5i replies
...so far with this patch, the rhel4 server seems to be very stable when
serving both nfs3 and nfs4 with krb5i. Continuing testing to make sure nothing
is broken by this.
This request was evaluated by Red Hat Kernel Team for inclusion in a Red Hat Enterprise Linux maintenance release, and has moved to bugzilla status POST. committed in stream U6 build 55.12. A test kernel with this patch is available from http://people.redhat.com/~jbaron/rhel4/ An advisory has been issued which should help the problem described in this bug report. This report is therefore being closed with a resolution of ERRATA. For more information on the solution and/or where to find the updated files, please follow the link below. You may reopen this bug report if the solution does not work for you. http://rhn.redhat.com/errata/RHBA-2007-0791.html |