Bug 785931
Summary: | NFS regression - READDIRPLUS / uninterruptible sleep / rpc_wait_bit_killable / huge LOAD | ||||||||
---|---|---|---|---|---|---|---|---|---|
Product: | Red Hat Enterprise Linux 6 | Reporter: | Marcus Alves Grando <marcus> | ||||||
Component: | kernel | Assignee: | Jeff Layton <jlayton> | ||||||
Status: | CLOSED DUPLICATE | QA Contact: | Red Hat Kernel QE team <kernel-qe> | ||||||
Severity: | high | Docs Contact: | |||||||
Priority: | high | ||||||||
Version: | 6.3 | CC: | akaiser, harshula, jlayton, pasteur, rwheeler, steved, tom, yankuncheng | ||||||
Target Milestone: | rc | Keywords: | Reopened | ||||||
Target Release: | --- | ||||||||
Hardware: | x86_64 | ||||||||
OS: | Linux | ||||||||
Whiteboard: | NFS | ||||||||
Fixed In Version: | Doc Type: | Bug Fix | |||||||
Doc Text: | Story Points: | --- | |||||||
Clone Of: | Environment: | ||||||||
Last Closed: | 2012-11-06 01:51:01 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
Marcus Alves Grando
2012-01-30 22:21:38 UTC
Hello, Maybe it's related with this one: https://bugzilla.redhat.com/show_bug.cgi?id=688130 I'm trying run with "nordirplus". Until now, looks fine. Tomorrow during the load it's possible to confirm. I don't know how exactly it's fixed in kernel.org. There's another BZ related with my 3rd problem. Maybe close that one with duplicate of this one, because other problems that need to be backported. https://bugzilla.redhat.com/show_bug.cgi?id=785830 Best regards Ok. We are testing those cenarios: 2.6.32-71.29.1 - Load +- 41 2.6.32-220.4.1 + patches above + nordirplus - Load +- 25 2.6.32-71 - Load +- 25 With nordirplus works fine. Do you need something else? Best regards Hello guys, I testes another kernel 2.6.32-244.el6.x86_64 provided by RedHat support, and has the same problem with all others. To make all things simple I tested only two kernels (2.6.32-71.29.1.el6.x86_64 and 2.6.32-244.el6.x86_64). I generated rpcdebug -m rpc -s all during 2 seconds and I'll add to BZ. Looking at nfsstat during this period, something is really wrong. Look below: * 2.6.32-71.29.1.el6.x86_64: RPC: calls: 7365 retrans: 0 authrefrsh: 0 NFS3: null: 0 getattr: 1426 setattr: 126 lookup: 973 access: 1607 readlink: 0 read: 1790 write: 72 create: 7 mkdir: 0 symlink: 0 mknod: 0 remove: 119 rmdir: 0 rename: 49 link: 85 readdir: 660 readdirplus: 390 fsstat: 0 fsinfo: 0 pathconf: 0 commit: 62 * 2.6.32-244.el6.x86_64: RPC: calls: 15963 retrans: 0 authrefrsh: 15964 NFS3: null: 0 getattr: 2187 setattr: 44 lookup: 636 access: 1781 readlink: 0 read: 8394 write: 54 create: 6 mkdir: 0 symlink: 0 mknod: 0 remove: 71 rmdir: 0 rename: 56 link: 42 readdir: 0 readdirplus: 2647 fsstat: 0 fsinfo: 0 pathconf: 0 commit: 46 The 2.6.32-244.el6.x86_64 server are running with 1/4 of users, comparated with another server. Looking the nfsstat you can see a huge increase in 'authrefrsh' and that all requests of readdir is goning to readdirplus. Besides, the server with 1/4 of users are doing 2x more calls. Comparing rpcdebug, I found this: * 2.6.32-71.29.1.el6.x86_64: kernel: RPC: 34691 call_start nfs3 proc READDIRPLUS (sync) kernel: RPC: 34691 call_reserve (status 0) kernel: RPC: 34691 reserved req ffff8801b8173598 xid d54ee4ec kernel: RPC: 34691 call_reserveresult (status 0) kernel: RPC: 34691 call_allocate (status 0) kernel: RPC: 34691 allocated buffer of size 572 at ffff88021efbb800 * 2.6.32-244.el6.x86_64:kernel: RPC: 17812 call_start nfs3 proc READDIRPLUS (sync) kernel: RPC: 17812 call_reserve (status 0) kernel: RPC: 17812 reserved req ffff8801b84681b0 xid 890edccb kernel: RPC: 17812 call_reserveresult (status 0) kernel: RPC: 17812 call_refresh (status 0) kernel: RPC: 17812 refreshing UNIX cred ffff8803f0a3e900 kernel: RPC: 17812 call_refreshresult (status 0) kernel: RPC: 17812 call_allocate (status 0) kernel: RPC: 17812 allocated buffer of size 572 at ffff8801c8683000 I don't know why 'call_refresh' are calling after 'call_reserveresult', but on the old behaviour it's not happens. Best regards Created attachment 569511 [details]
rpcdebug -m rpc -s all on 2.6.32-71.29.1.el6.x86_64
Created attachment 569512 [details]
rpcdebug -m rpc -s all on 2.6.32-244.el6.x86_64
Using CentOS kernel 2.6.32-220.7.1.el6.x86_64 and I also see the authrefrsh count skyrocketing: Client rpc stats: calls retrans authrefrsh 105283279 0 105285429 Client nfs v3: null getattr setattr lookup access readlink 0 0% 55955 0% 4901 0% 8735 0% 10309 0% 87 0% read write create mkdir symlink mknod 54463085 51% 50703785 48% 4352 0% 193 0% 176 0% 0 0% remove rmdir rename link readdir readdirplus 1136 0% 54 0% 264 0% 2 0% 0 0% 905 0% fsstat fsinfo pathconf commit 1965 0% 10 0% 5 0% 0 0% I'm working with large files (10s of GB) and in the middle of sequential reads and writes it stalls to a few KB/s. If I do an ls (from a separate terminal) of the directrory where those files are then the speed resumes to the nornal 100MB/s while ls itself is running for 3-4 minutes. NFSv4 previously crashed the whole box, that's why I switched to NFS3. I think the first thing that needs to happen here is to define this problem better. It looks like there are 3-4 different problem reports all squashed together here. Some of those are likely already fixed in 6.3 kernels. I'm really only interested in problems that are not already fixed in 6.3 kernels. What we probably need to have the reporters of this bug test some very recent 6.3 kernels (especially those with the appropriate readdir and other NFS fixes), and then restate the problems that you're seeing on top of that. For instance, Marcus said: "I testes another kernel 2.6.32-244.el6.x86_64 provided by RedHat support, and has the same problem with all others." ...what I'm not clear on is which problem you mean since you enumerated 3-4 different problems originally. He also said: "Looking the nfsstat you can see a huge increase in 'authrefrsh' and that all requests of readdir is goning to readdirplus." I'm not sure we can call the authrefresh counter increasing a "problem". It may just be an artefact of other changes in the RPC layer. IOW, it may be a possible symptom, but is not a problem in and of itself. In any case, it does not indicate an increase in the number of RPC calls, but rather an increase in the number of calls to refresh the credentials for making a new RPC call. For anything but GSSAPI, that's basically just a set_bit call. The change to use readdirplus more widely is also expected. A patch series added to RHEL6.1 removed the readdir plus directory size limit. That may or may not have a performance impact with your workload. If you're experiencing performance issues, then it's critical that we understand what is actually slow, preferably at the system call level. Only with that info will we be able to make progress here. You'll also need to help quantify the slowness. IOW, we need to understand what got slower and how much slower it is. Without that, we can't quantify any possible performance improvement that we might make. Hello Jeff, (In reply to comment #11) > I think the first thing that needs to happen here is to define this problem > better. It looks like there are 3-4 different problem reports all > squashed together here. Some of those are likely already fixed in 6.3 kernels. > > I'm really only interested in problems that are not already fixed in 6.3 > kernels. What we probably need to have the reporters of this bug test some > very recent 6.3 kernels (especially those with the appropriate readdir and > other NFS fixes), and then restate the problems that you're seeing on top > of that. > > For instance, Marcus said: > > "I testes another kernel 2.6.32-244.el6.x86_64 provided by RedHat support, and > has the same problem with all others." Sure, I'll test the latest 6.3 kernel and describe better the problems. Can you provide the latest 6.3 kernel with perf rpm? With perf top I saw a number of calls that I can't see on the latest 6.1 kernel, like below: PerfTop: 3486 irqs/sec kernel:74.6% exact: 0.0% [1000Hz cycles], (all, 12 CPUs) --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- samples pcnt function DSO _______ _____ ___________________________________ _________________________________________________________________________________ 3346.00 5.2% __GI_vfprintf /lib64/libc-2.12.so 2169.00 3.4% inflate /lib64/libz.so.1.2.3 1610.00 2.5% nfs_permission /lib/modules/2.6.32-220.7.1.el6.x86_64/kernel/fs/nfs/nfs.ko 1442.00 2.3% _IO_default_xsputn_internal /lib64/libc-2.12.so 1437.00 2.2% inflate_fast /lib64/libz.so.1.2.3 1110.00 1.7% __GI_____strtoll_l_internal /lib64/libc-2.12.so 988.00 1.5% find_inode [kernel.kallsyms] 922.00 1.4% rpc_wake_up_queued_task /lib/modules/2.6.32-220.7.1.el6.x86_64/kernel/net/sunrpc/sunrpc.ko 913.00 1.4% _spin_lock [kernel.kallsyms] 890.00 1.4% __d_lookup [kernel.kallsyms] 850.00 1.3% TrrMailFolderGetNextMessage /usr/lib/libtrrmail.so.3.5.1 836.00 1.3% bnx2_poll_work /lib/modules/2.6.32-220.7.1.el6.x86_64/kernel/drivers/net/bnx2.ko 801.00 1.3% __memcpy [kernel.kallsyms] 692.00 1.1% find_busiest_group [kernel.kallsyms] 685.00 1.1% rpc_free_client /lib/modules/2.6.32-220.7.1.el6.x86_64/kernel/net/sunrpc/sunrpc.ko 663.00 1.0% find_next_bit [kernel.kallsyms] 641.00 1.0% copy_user_generic_string [kernel.kallsyms] 610.00 1.0% clear_page_c [kernel.kallsyms] 596.00 0.9% __strchr_sse2 /lib64/libc-2.12.so 570.00 0.9% generic_pkt_to_tuple /lib/modules/2.6.32-220.7.1.el6.x86_64/kernel/net/netfilter/nf_conntrack.ko 541.00 0.8% _itoa_word /lib64/libc-2.12.so 535.00 0.8% memcpy /lib64/libc-2.12.so 485.00 0.8% __list_add [kernel.kallsyms] 465.00 0.7% xs_udp_timer /lib/modules/2.6.32-220.7.1.el6.x86_64/kernel/net/sunrpc/sunrpc.ko 437.00 0.7% nf_conntrack_free /lib/modules/2.6.32-220.7.1.el6.x86_64/kernel/net/netfilter/nf_conntrack.ko 436.00 0.7% kmem_cache_alloc [kernel.kallsyms] 429.00 0.7% inode_init_once [kernel.kallsyms] 424.00 0.7% _int_malloc /lib64/libc-2.12.so 423.00 0.7% kfree [kernel.kallsyms] 419.00 0.7% nfs_post_op_update_inode /lib/modules/2.6.32-220.7.1.el6.x86_64/kernel/fs/nfs/nfs.ko 411.00 0.6% TrrMailLog /usr/lib/libtrrmail.so.3.5.1 404.00 0.6% crc32 /lib64/libz.so.1.2.3 394.00 0.6% TrrMailMsgGetPath /usr/lib/libtrrmail.so.3.5.1 392.00 0.6% nfs_cache_upcall /lib/modules/2.6.32-220.7.1.el6.x86_64/kernel/fs/nfs/nfs.ko > > ...what I'm not clear on is which problem you mean since you enumerated 3-4 > different problems originally. He also said: > > "Looking the nfsstat you can see a huge increase in 'authrefrsh' and that all > requests of readdir is goning to readdirplus." > > I'm not sure we can call the authrefresh counter increasing a "problem". It > may just be an artefact of other changes in the RPC layer. IOW, it may be a > possible symptom, but is not a problem in and of itself. In any case, it > does not indicate an increase in the number of RPC calls, but rather an > increase in the number of calls to refresh the credentials for making a new > RPC call. For anything but GSSAPI, that's basically just a set_bit call. Looking the number of rpc calls seems that's nothing change. It's almost equal the number of 6.1 and 6.3 kernel. > > The change to use readdirplus more widely is also expected. A patch series > added to RHEL6.1 removed the readdir plus directory size limit. That may or > may not have a performance impact with your workload. > > If you're experiencing performance issues, then it's critical that we > understand what is actually slow, preferably at the system call level. Only > with that info will we be able to make progress here. You'll also need to > help quantify the slowness. IOW, we need to understand what got slower and > how much slower it is. Without that, we can't quantify any possible performance > improvement that we might make. I'll try to figure out with the latest kernel. Thanks (In reply to comment #12) > Sure, I'll test the latest 6.3 kernel and describe better the problems. Can you > provide the latest 6.3 kernel with perf rpm? With perf top I saw a number of > calls that I can't see on the latest 6.1 kernel, like below: > No, that will need to be done by the support person handling the support case. Please ask them to give you the latest kernel possible so we can rule out any fixes that are already slated for 6.3. As of today that would be -257.el6. (In reply to comment #13) > (In reply to comment #12) > > > Sure, I'll test the latest 6.3 kernel and describe better the problems. Can you > > provide the latest 6.3 kernel with perf rpm? With perf top I saw a number of > > calls that I can't see on the latest 6.1 kernel, like below: > > > > No, that will need to be done by the support person handling the support case. > Please ask them to give you the latest kernel possible so we can rule out any > fixes that are already slated for 6.3. As of today that would be -257.el6. OK. Any more word on this? Did the latest kernel help anything? Development Management has reviewed and declined this request. You may appeal this decision by reopening this request. Hello Jeff, During last two days I returned to this problem. I have found the problem. It's related with the remove the limit to use READDIRPLUS (NFS: remove readdir plus limit). The fix below (NFS: Adapt readdirplus to application usage patterns) solve my problem, can you add on the default EL kernel? http://git.kernel.org/?p=linux/kernel/git/stable/linux-stable.git;a=commitdiff;h=d69ee9b85541a69a1092f5da675bd23256dc62af For all the other problems related on the beginning, all it's fixed until -279.11.1. Best regards *** This bug has been marked as a duplicate of bug 819891 *** |