2008-10-22 09:37:31

by Max Kellermann

[permalink] [raw]
Subject: High load in 2.6.27, NFS / rpcauth_lookup_credcache()?

Hi,

after I was able to fix http://lkml.org/lkml/2008/10/17/147, the
server which was already upgraded to 2.6.27.2 still gets very high
load. It is a web server with NFS file storage (NetApp), and while
the others in the cluster (kernel 2.6.25) have a load of 1-3, 2.6.27.2
gets 30-50.

I did an oprofile, with the following results (server just started,
load "only" 5-10):

87593 56.1116 (no location information) vmlinux
vmlinux rpcauth_lookup_credcache
16037 10.2732 auth_generic.c:0 vmlinux
vmlinux generic_match
6460 4.1382 (no location information) php4
php4 (no symbols)
2478 1.5874 (no location information) libc-2.7.so
libc-2.7.so (no symbols)
[...]

We havn't configured any special authentication method. It is a NFSv3
over UDP mount, but the kernel has NFSv4 and therefore KRB5 enabled.

Any ideas why rpcauth_lookup_credcache() goes overboard with CPU
usage?

Max


Attachments:
(No filename) (984.00 B)
.config (38.14 kB)
Download all attachments

2008-10-22 17:56:29

by J. Bruce Fields

[permalink] [raw]
Subject: Re: High load in 2.6.27, NFS / rpcauth_lookup_credcache()?

On Wed, Oct 22, 2008 at 11:12:08AM +0200, Max Kellermann wrote:
> Hi,
>
> after I was able to fix http://lkml.org/lkml/2008/10/17/147, the
> server which was already upgraded to 2.6.27.2 still gets very high
> load. It is a web server with NFS file storage (NetApp), and while
> the others in the cluster (kernel 2.6.25) have a load of 1-3, 2.6.27.2
> gets 30-50.
>
> I did an oprofile, with the following results (server just started,
> load "only" 5-10):

Well, there's only 7 patches to net/sunrpc/auth.c between 2.6.25 and
today, so worst case a 'git bisect v2.6.25..v2.6.27 net/sunrpc/auth.c'
might not be too bad.

No particular idea why rpcauth_lookup_credcache would be a problem,
though.

--b.

>
> 87593 56.1116 (no location information) vmlinux
> vmlinux rpcauth_lookup_credcache
> 16037 10.2732 auth_generic.c:0 vmlinux
> vmlinux generic_match
> 6460 4.1382 (no location information) php4
> php4 (no symbols)
> 2478 1.5874 (no location information) libc-2.7.so
> libc-2.7.so (no symbols)
> [...]
>
> We havn't configured any special authentication method. It is a NFSv3
> over UDP mount, but the kernel has NFSv4 and therefore KRB5 enabled.
>
> Any ideas why rpcauth_lookup_credcache() goes overboard with CPU
> usage?
>
> Max

2008-10-23 12:36:43

by Max Kellermann

[permalink] [raw]
Subject: Re: High load in 2.6.27, NFS / rpcauth_lookup_credcache()?

On 2008/10/22 11:12, Max Kellermann <[email protected]> wrote:
> after I was able to fix http://lkml.org/lkml/2008/10/17/147, the
> server which was already upgraded to 2.6.27.2 still gets very high
> load. It is a web server with NFS file storage (NetApp), and while
> the others in the cluster (kernel 2.6.25) have a load of 1-3, 2.6.27.2
> gets 30-50.
>
> I did an oprofile, with the following results (server just started,
> load "only" 5-10):
>
> 87593 56.1116 (no location information) vmlinux
> vmlinux rpcauth_lookup_credcache
> 16037 10.2732 auth_generic.c:0 vmlinux
> vmlinux generic_match
> 6460 4.1382 (no location information) php4
> php4 (no symbols)
> 2478 1.5874 (no location information) libc-2.7.so
> libc-2.7.so (no symbols)
> [...]
>
> We havn't configured any special authentication method. It is a NFSv3
> over UDP mount, but the kernel has NFSv4 and therefore KRB5 enabled.
>
> Any ideas why rpcauth_lookup_credcache() goes overboard with CPU
> usage?

I have bisected the problem: 98a8e323 is the result ("SUNRPC: Add a
helper rpcauth_lookup_generic_cred()"). 5c691044 is ok.

See the attached oprofile annotation data for both commits. I guess
that the function rpcauth_lookup_credcache() is waiting for a spinlock
too often and too long. Trond, any idea?

Harry: added you to Cc because your problem sounds similar.

Max


Attachments:
(No filename) (1.42 kB)
annotate.98a8e3239427051f5d44f2025b398bdcc3918f37 (7.66 kB)
annotate.5c691044ecbca04dd558fca4c754121689fe1b34 (7.66 kB)
Download all attachments

2008-10-23 14:56:14

by Trond Myklebust

[permalink] [raw]
Subject: Re: High load in 2.6.27, NFS / rpcauth_lookup_credcache()?

On Thu, 2008-10-23 at 14:36 +0200, Max Kellermann wrote:
> On 2008/10/22 11:12, Max Kellermann <[email protected]> wrote:
> > after I was able to fix http://lkml.org/lkml/2008/10/17/147, the
> > server which was already upgraded to 2.6.27.2 still gets very high
> > load. It is a web server with NFS file storage (NetApp), and while
> > the others in the cluster (kernel 2.6.25) have a load of 1-3, 2.6.27.2
> > gets 30-50.
> >
> > I did an oprofile, with the following results (server just started,
> > load "only" 5-10):
> >
> > 87593 56.1116 (no location information) vmlinux
> > vmlinux rpcauth_lookup_credcache
> > 16037 10.2732 auth_generic.c:0 vmlinux
> > vmlinux generic_match
> > 6460 4.1382 (no location information) php4
> > php4 (no symbols)
> > 2478 1.5874 (no location information) libc-2.7.so
> > libc-2.7.so (no symbols)
> > [...]
> >
> > We havn't configured any special authentication method. It is a NFSv3
> > over UDP mount, but the kernel has NFSv4 and therefore KRB5 enabled.
> >
> > Any ideas why rpcauth_lookup_credcache() goes overboard with CPU
> > usage?
>
> I have bisected the problem: 98a8e323 is the result ("SUNRPC: Add a
> helper rpcauth_lookup_generic_cred()"). 5c691044 is ok.
>
> See the attached oprofile annotation data for both commits. I guess
> that the function rpcauth_lookup_credcache() is waiting for a spinlock
> too often and too long. Trond, any idea?

Can you add a '-v' to the rpc.gssd daemon startup line? I'd like to see
how often you are creating new gss contexts.

> Harry: added you to Cc because your problem sounds similar.

Harry's problem is should be unrelated. afaik, he is seeing a problem
with userland RPC code, not kernel rpc code.

Trond

2008-10-24 08:39:26

by Max Kellermann

[permalink] [raw]
Subject: Re: High load in 2.6.27, NFS / rpcauth_lookup_credcache()?

On 2008/10/23 16:55, Trond Myklebust <[email protected]> wrote:
> Can you add a '-v' to the rpc.gssd daemon startup line? I'd like to see
> how often you are creating new gss contexts.

There is no rpc.gssd running on any of these servers, we're using
plain NFSv3 without (protocol based) authentication. Do you want me
to start it anyway?

Max

2008-10-24 18:09:37

by Trond Myklebust

[permalink] [raw]
Subject: Re: High load in 2.6.27, NFS / rpcauth_lookup_credcache()?

On Fri, 2008-10-24 at 10:39 +0200, Max Kellermann wrote:
> On 2008/10/23 16:55, Trond Myklebust <[email protected]> wrote:
> > Can you add a '-v' to the rpc.gssd daemon startup line? I'd like to see
> > how often you are creating new gss contexts.
>
> There is no rpc.gssd running on any of these servers, we're using
> plain NFSv3 without (protocol based) authentication. Do you want me
> to start it anyway?

Sorry. I misread your email. I read it as saying that you had krb5
enabled on your mountpoint, but what you really said was just that you
have compiled up the module.

OK, could you please describe your environment a bit. Do you have lots
of different users logged in at the same time, or do you perhaps use
newgrp or su to switch uid/gids a lot on your processes?
I'm trying to see if there might be a reason for the lookup in the
credcache being such a heavy duty operation in your setup.

Cheers
Trond

2008-10-27 09:58:55

by Max Kellermann

[permalink] [raw]
Subject: Re: High load in 2.6.27, NFS / rpcauth_lookup_credcache()?

On 2008/10/24 20:09, Trond Myklebust <[email protected]> wrote:
> OK, could you please describe your environment a bit. Do you have lots
> of different users logged in at the same time, or do you perhaps use
> newgrp or su to switch uid/gids a lot on your processes?
> I'm trying to see if there might be a reason for the lookup in the
> credcache being such a heavy duty operation in your setup.

It's a web server for shared hosting. The web space is mounted via
NFSv3 from a NetApp. There is a huge number of web sites on this
cluster. All web sites are owned by the same UID, and the web server
runs as a different UID (read-only access).

Each time a CGI starts, its uid is changed to the one "owner" UID
(similar to mod_suexec, but there's only one UID for all customer
accounts). Each time a CGI starts, its chroot (pivot_root) is
constructed with several bind mounts (in a separate namespace with
CLONE_NEWNS).

There are no new users or groups being created. There are only 2 UIDs
accessing NFS: the webserver (ro) and CGI (rw).

Max

2008-10-27 15:48:38

by Trond Myklebust

[permalink] [raw]
Subject: Re: High load in 2.6.27, NFS / rpcauth_lookup_credcache()?

On Mon, 2008-10-27 at 10:58 +0100, Max Kellermann wrote:
> On 2008/10/24 20:09, Trond Myklebust <[email protected]> wrote:
> > OK, could you please describe your environment a bit. Do you have lots
> > of different users logged in at the same time, or do you perhaps use
> > newgrp or su to switch uid/gids a lot on your processes?
> > I'm trying to see if there might be a reason for the lookup in the
> > credcache being such a heavy duty operation in your setup.
>
> It's a web server for shared hosting. The web space is mounted via
> NFSv3 from a NetApp. There is a huge number of web sites on this
> cluster. All web sites are owned by the same UID, and the web server
> runs as a different UID (read-only access).
>
> Each time a CGI starts, its uid is changed to the one "owner" UID
> (similar to mod_suexec, but there's only one UID for all customer
> accounts). Each time a CGI starts, its chroot (pivot_root) is
> constructed with several bind mounts (in a separate namespace with
> CLONE_NEWNS).
>
> There are no new users or groups being created. There are only 2 UIDs
> accessing NFS: the webserver (ro) and CGI (rw).

OK. That points a finger at the garbage collector. Does the following
patch help at all?

Cheers
Trond
------------------------------------------------------------------------
From: Trond Myklebust <[email protected]>
Date: Mon, 27 Oct 2008 11:43:48 -0400
SUNRPC: Fix rpcauth_prune_expired

We need to make sure that we don't remove creds from the cred_unused list
if they are still under the moratorium, or else they will never get
garbage collected.

Signed-off-by: Trond Myklebust <[email protected]>
---

net/sunrpc/auth.c | 16 +++++++++-------
1 files changed, 9 insertions(+), 7 deletions(-)


diff --git a/net/sunrpc/auth.c b/net/sunrpc/auth.c
index 436bf1b..a045a12 100644
--- a/net/sunrpc/auth.c
+++ b/net/sunrpc/auth.c
@@ -228,19 +228,21 @@ static int
rpcauth_prune_expired(struct list_head *free, int nr_to_scan)
{
spinlock_t *cache_lock;
- struct rpc_cred *cred;
+ struct rpc_cred *cred, *next;
unsigned long expired = jiffies - RPC_AUTH_EXPIRY_MORATORIUM;

- while (!list_empty(&cred_unused)) {
- cred = list_entry(cred_unused.next, struct rpc_cred, cr_lru);
+ list_for_each_entry_safe(cred, next, &cred_unused, cr_lru) {
+
+ /* Enforce a 60 second garbage collection moratorium */
+ if (time_in_range(cred->cr_expire, expired, jiffies) &&
+ test_bit(RPCAUTH_CRED_HASHED, &cred->cr_flags) != 0)
+ continue;
+
list_del_init(&cred->cr_lru);
number_cred_unused--;
if (atomic_read(&cred->cr_count) != 0)
continue;
- /* Enforce a 5 second garbage collection moratorium */
- if (time_in_range(cred->cr_expire, expired, jiffies) &&
- test_bit(RPCAUTH_CRED_UPTODATE, &cred->cr_flags) != 0)
- continue;
+
cache_lock = &cred->cr_auth->au_credcache->lock;
spin_lock(cache_lock);
if (atomic_read(&cred->cr_count) == 0) {

2008-11-17 12:36:01

by Max Kellermann

[permalink] [raw]
Subject: Re: High load in 2.6.27, NFS / rpcauth_lookup_credcache()?

On 2008/10/27 16:48, Trond Myklebust <[email protected]> wrote:
> OK. That points a finger at the garbage collector. Does the following
> patch help at all?

Hi Trond,

the server's load seems to be a little bit lower with 2.6.27.6 plus
your patch, but OProfile still gives me 45% in
rpcauth_lookup_credcache(). See:

1060627 45.1474 (no location information) rpcauth_lookup_credcache
289362 12.3172 auth_generic.c:0 generic_match
31886 1.3573 page_alloc.c:0 get_page_from_freelist
23932 1.0187 (no location information) page_fault
22176 0.9440 (no location information) schedule
14613 0.6220 (no location information) __d_lookup
[...]

Max

2008-11-19 22:31:20

by Trond Myklebust

[permalink] [raw]
Subject: Re: High load in 2.6.27, NFS / rpcauth_lookup_credcache()?

On Mon, 2008-11-17 at 13:35 +0100, Max Kellermann wrote:
> On 2008/10/27 16:48, Trond Myklebust <[email protected]> wrote:
> > OK. That points a finger at the garbage collector. Does the following
> > patch help at all?
>
> Hi Trond,
>
> the server's load seems to be a little bit lower with 2.6.27.6 plus
> your patch, but OProfile still gives me 45% in
> rpcauth_lookup_credcache(). See:
>
> 1060627 45.1474 (no location information) rpcauth_lookup_credcache
> 289362 12.3172 auth_generic.c:0 generic_match
> 31886 1.3573 page_alloc.c:0 get_page_from_freelist
> 23932 1.0187 (no location information) page_fault
> 22176 0.9440 (no location information) schedule
> 14613 0.6220 (no location information) __d_lookup
> [...]
>
> Max

Looking at the above, it seems that you're spending an inordinate amount
of time in generic_match too.
Could you see if the following patch helps?

Cheers
Trond

-------------------------------------------------------------------------------
From: Trond Myklebust <[email protected]>
SUNRPC: Fix up generic_match()

Cut down on the number of similar copies of group_info.

Signed-off-by: Trond Myklebust <[email protected]>
---

net/sunrpc/auth_generic.c | 20 ++++++++++++++++++--
1 files changed, 18 insertions(+), 2 deletions(-)


diff --git a/net/sunrpc/auth_generic.c b/net/sunrpc/auth_generic.c
index 744b79f..4028502 100644
--- a/net/sunrpc/auth_generic.c
+++ b/net/sunrpc/auth_generic.c
@@ -133,13 +133,29 @@ static int
generic_match(struct auth_cred *acred, struct rpc_cred *cred, int flags)
{
struct generic_cred *gcred = container_of(cred, struct generic_cred, gc_base);
+ int i;

if (gcred->acred.uid != acred->uid ||
gcred->acred.gid != acred->gid ||
- gcred->acred.group_info != acred->group_info ||
gcred->acred.machine_cred != acred->machine_cred)
- return 0;
+ goto out_nomatch;
+
+ /* Optimisation in the case where pointers are identical... */
+ if (gcred->acred.group_info == acred->group_info)
+ goto out_match;
+
+ /* Slow path... */
+ if (gcred->acred.group_info->ngroups != acred->group_info->ngroups)
+ goto out_nomatch;
+ for (i = 0; i < gcred->acred.group_info->ngroups; i++) {
+ if (GROUP_AT(gcred->acred.group_info, i) !=
+ GROUP_AT(acred->group_info, i))
+ goto out_nomatch;
+ }
+out_match:
return 1;
+out_nomatch:
+ return 0;
}

void __init rpc_init_generic_auth(void)

2008-11-20 14:08:42

by Max Kellermann

[permalink] [raw]
Subject: Re: High load in 2.6.27, NFS / rpcauth_lookup_credcache()?

On 2008/11/19 23:31, Trond Myklebust <[email protected]> wrote:
> Looking at the above, it seems that you're spending an inordinate amount
> of time in generic_match too.
> Could you see if the following patch helps?

That fixes the problem. The first kernel symbol in oprofile is the
tg3 network driver at 2%.

Max

2008-12-15 23:57:31

by Harry Edmon

[permalink] [raw]
Subject: Re: High load in 2.6.27, NFS / rpcauth_lookup_credcache()?

Trond Myklebust wrote:
> On Thu, 2008-10-23 at 14:36 +0200, Max Kellermann wrote:
>
>> On 2008/10/22 11:12, Max Kellermann <[email protected]> wrote:
>>
>>> after I was able to fix http://lkml.org/lkml/2008/10/17/147, the
>>> server which was already upgraded to 2.6.27.2 still gets very high
>>> load. It is a web server with NFS file storage (NetApp), and while
>>> the others in the cluster (kernel 2.6.25) have a load of 1-3, 2.6.27.2
>>> gets 30-50.
>>>
>>> I did an oprofile, with the following results (server just started,
>>> load "only" 5-10):
>>>
>>> 87593 56.1116 (no location information) vmlinux
>>> vmlinux rpcauth_lookup_credcache
>>> 16037 10.2732 auth_generic.c:0 vmlinux
>>> vmlinux generic_match
>>> 6460 4.1382 (no location information) php4
>>> php4 (no symbols)
>>> 2478 1.5874 (no location information) libc-2.7.so
>>> libc-2.7.so (no symbols)
>>> [...]
>>>
>>> We havn't configured any special authentication method. It is a NFSv3
>>> over UDP mount, but the kernel has NFSv4 and therefore KRB5 enabled.
>>>
>>> Any ideas why rpcauth_lookup_credcache() goes overboard with CPU
>>> usage?
>>>
>> I have bisected the problem: 98a8e323 is the result ("SUNRPC: Add a
>> helper rpcauth_lookup_generic_cred()"). 5c691044 is ok.
>>
>> See the attached oprofile annotation data for both commits. I guess
>> that the function rpcauth_lookup_credcache() is waiting for a spinlock
>> too often and too long. Trond, any idea?
>>
>
> Can you add a '-v' to the rpc.gssd daemon startup line? I'd like to see
> how often you are creating new gss contexts.
>
>
>> Harry: added you to Cc because your problem sounds similar.
>>
>
> Harry's problem is should be unrelated. afaik, he is seeing a problem
> with userland RPC code, not kernel rpc code.
>
> Trond
>
>
I am finally getting some time to look at my problem that I originally
reported in October (SUNRPC problem with 2.6.26 and beyond), and I am
seeing the same behavior as Max Kellermann when my machine slows as I
described earlier. The system in question is currently running
2.6.27.7. Here is what I see when it is misbehaving:

samples % image name app name
symbol name
11380517 57.4191 sunrpc.ko sunrpc
rpcauth_lookup_credcache
3263657 16.4664 sunrpc.ko sunrpc
generic_match
1081287 5.4555 vmlinux vmlinux
copy_user_generic_string
499407 2.5197 vmlinux vmlinux
__posix_lock_file
[...]

And here is what I see when I stop the programs that are chewing up all
the system time, and then starting them up again:

samples % image name app name
symbol name
6372650 21.7978 vmlinux vmlinux
copy_user_generic_string
5401386 18.4755 sunrpc.ko sunrpc
rpcauth_lookup_credcache
3018753 10.3257 vmlinux vmlinux
__posix_lock_file
1050095 3.5919 sunrpc.ko sunrpc
generic_match


and I am not using Kerberos with NFSv4 (i.e. no rpc.gssd). Did you ever
find a solution for this problem with rpcauth_lookup_credcache?

--

Dr. Harry Edmon E-MAIL: [email protected]
206-543-0547 [email protected]
Dept of Atmospheric Sciences FAX: 206-543-0308
University of Washington, Box 351640, Seattle, WA 98195-1640

2008-12-16 13:02:51

by Trond Myklebust

[permalink] [raw]
Subject: Re: High load in 2.6.27, NFS / rpcauth_lookup_credcache()?

On Mon, 2008-12-15 at 15:44 -0800, Harry Edmon wrote:
> Trond Myklebust wrote:
> > On Thu, 2008-10-23 at 14:36 +0200, Max Kellermann wrote:
> >
> >> On 2008/10/22 11:12, Max Kellermann <[email protected]> wrote:
> >>
> >>> after I was able to fix http://lkml.org/lkml/2008/10/17/147, the
> >>> server which was already upgraded to 2.6.27.2 still gets very high
> >>> load. It is a web server with NFS file storage (NetApp), and while
> >>> the others in the cluster (kernel 2.6.25) have a load of 1-3, 2.6.27.2
> >>> gets 30-50.
> >>>
> >>> I did an oprofile, with the following results (server just started,
> >>> load "only" 5-10):
> >>>
> >>> 87593 56.1116 (no location information) vmlinux
> >>> vmlinux rpcauth_lookup_credcache
> >>> 16037 10.2732 auth_generic.c:0 vmlinux
> >>> vmlinux generic_match
> >>> 6460 4.1382 (no location information) php4
> >>> php4 (no symbols)
> >>> 2478 1.5874 (no location information) libc-2.7.so
> >>> libc-2.7.so (no symbols)
> >>> [...]
> >>>
> >>> We havn't configured any special authentication method. It is a NFSv3
> >>> over UDP mount, but the kernel has NFSv4 and therefore KRB5 enabled.
> >>>
> >>> Any ideas why rpcauth_lookup_credcache() goes overboard with CPU
> >>> usage?
> >>>
> >> I have bisected the problem: 98a8e323 is the result ("SUNRPC: Add a
> >> helper rpcauth_lookup_generic_cred()"). 5c691044 is ok.
> >>
> >> See the attached oprofile annotation data for both commits. I guess
> >> that the function rpcauth_lookup_credcache() is waiting for a spinlock
> >> too often and too long. Trond, any idea?
> >>
> >
> > Can you add a '-v' to the rpc.gssd daemon startup line? I'd like to see
> > how often you are creating new gss contexts.
> >
> >
> >> Harry: added you to Cc because your problem sounds similar.
> >>
> >
> > Harry's problem is should be unrelated. afaik, he is seeing a problem
> > with userland RPC code, not kernel rpc code.
> >
> > Trond
> >
> >
> I am finally getting some time to look at my problem that I originally
> reported in October (SUNRPC problem with 2.6.26 and beyond), and I am
> seeing the same behavior as Max Kellermann when my machine slows as I
> described earlier. The system in question is currently running
> 2.6.27.7. Here is what I see when it is misbehaving:
>
> samples % image name app name
> symbol name
> 11380517 57.4191 sunrpc.ko sunrpc
> rpcauth_lookup_credcache
> 3263657 16.4664 sunrpc.ko sunrpc
> generic_match
> 1081287 5.4555 vmlinux vmlinux
> copy_user_generic_string
> 499407 2.5197 vmlinux vmlinux
> __posix_lock_file
> [...]
>
> And here is what I see when I stop the programs that are chewing up all
> the system time, and then starting them up again:
>
> samples % image name app name
> symbol name
> 6372650 21.7978 vmlinux vmlinux
> copy_user_generic_string
> 5401386 18.4755 sunrpc.ko sunrpc
> rpcauth_lookup_credcache
> 3018753 10.3257 vmlinux vmlinux
> __posix_lock_file
> 1050095 3.5919 sunrpc.ko sunrpc
> generic_match
>
>
> and I am not using Kerberos with NFSv4 (i.e. no rpc.gssd). Did you ever
> find a solution for this problem with rpcauth_lookup_credcache?

http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git&a=commitdiff&h=23918b03060f6e572168fdde1798a905679d2e06

Trond

2008-12-16 21:22:48

by Willy Tarreau

[permalink] [raw]
Subject: Re: High load in 2.6.27, NFS / rpcauth_lookup_credcache()?

On Tue, Dec 16, 2008 at 08:02:33AM -0500, Trond Myklebust wrote:
> On Mon, 2008-12-15 at 15:44 -0800, Harry Edmon wrote:
> > Trond Myklebust wrote:
> > > On Thu, 2008-10-23 at 14:36 +0200, Max Kellermann wrote:
> > >
> > >> On 2008/10/22 11:12, Max Kellermann <[email protected]> wrote:
> > >>
> > >>> after I was able to fix http://lkml.org/lkml/2008/10/17/147, the
> > >>> server which was already upgraded to 2.6.27.2 still gets very high
> > >>> load. It is a web server with NFS file storage (NetApp), and while
> > >>> the others in the cluster (kernel 2.6.25) have a load of 1-3, 2.6.27.2
> > >>> gets 30-50.
> > >>>
> > >>> I did an oprofile, with the following results (server just started,
> > >>> load "only" 5-10):
> > >>>
> > >>> 87593 56.1116 (no location information) vmlinux
> > >>> vmlinux rpcauth_lookup_credcache
> > >>> 16037 10.2732 auth_generic.c:0 vmlinux
> > >>> vmlinux generic_match
> > >>> 6460 4.1382 (no location information) php4
> > >>> php4 (no symbols)
> > >>> 2478 1.5874 (no location information) libc-2.7.so
> > >>> libc-2.7.so (no symbols)
> > >>> [...]
> > >>>
> > >>> We havn't configured any special authentication method. It is a NFSv3
> > >>> over UDP mount, but the kernel has NFSv4 and therefore KRB5 enabled.
> > >>>
> > >>> Any ideas why rpcauth_lookup_credcache() goes overboard with CPU
> > >>> usage?
> > >>>
> > >> I have bisected the problem: 98a8e323 is the result ("SUNRPC: Add a
> > >> helper rpcauth_lookup_generic_cred()"). 5c691044 is ok.
> > >>
> > >> See the attached oprofile annotation data for both commits. I guess
> > >> that the function rpcauth_lookup_credcache() is waiting for a spinlock
> > >> too often and too long. Trond, any idea?
> > >>
> > >
> > > Can you add a '-v' to the rpc.gssd daemon startup line? I'd like to see
> > > how often you are creating new gss contexts.
> > >
> > >
> > >> Harry: added you to Cc because your problem sounds similar.
> > >>
> > >
> > > Harry's problem is should be unrelated. afaik, he is seeing a problem
> > > with userland RPC code, not kernel rpc code.
> > >
> > > Trond
> > >
> > >
> > I am finally getting some time to look at my problem that I originally
> > reported in October (SUNRPC problem with 2.6.26 and beyond), and I am
> > seeing the same behavior as Max Kellermann when my machine slows as I
> > described earlier. The system in question is currently running
> > 2.6.27.7. Here is what I see when it is misbehaving:
> >
> > samples % image name app name
> > symbol name
> > 11380517 57.4191 sunrpc.ko sunrpc
> > rpcauth_lookup_credcache
> > 3263657 16.4664 sunrpc.ko sunrpc
> > generic_match
> > 1081287 5.4555 vmlinux vmlinux
> > copy_user_generic_string
> > 499407 2.5197 vmlinux vmlinux
> > __posix_lock_file
> > [...]
> >
> > And here is what I see when I stop the programs that are chewing up all
> > the system time, and then starting them up again:
> >
> > samples % image name app name
> > symbol name
> > 6372650 21.7978 vmlinux vmlinux
> > copy_user_generic_string
> > 5401386 18.4755 sunrpc.ko sunrpc
> > rpcauth_lookup_credcache
> > 3018753 10.3257 vmlinux vmlinux
> > __posix_lock_file
> > 1050095 3.5919 sunrpc.ko sunrpc
> > generic_match
> >
> >
> > and I am not using Kerberos with NFSv4 (i.e. no rpc.gssd). Did you ever
> > find a solution for this problem with rpcauth_lookup_credcache?
>
> http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git&a=commitdiff&h=23918b03060f6e572168fdde1798a905679d2e06

Trond, this should be included into next stable, right ?

It's fortunate because I know someone else who recently described me the
same problem under the same circumstances when migrating from 2.6.22 to
2.6.27.

Regards,
Willy

2008-12-16 23:27:44

by Greg KH

[permalink] [raw]
Subject: Re: [stable] High load in 2.6.27, NFS / rpcauth_lookup_credcache()?

On Tue, Dec 16, 2008 at 10:21:55PM +0100, Willy Tarreau wrote:
> On Tue, Dec 16, 2008 at 08:02:33AM -0500, Trond Myklebust wrote:
> > > and I am not using Kerberos with NFSv4 (i.e. no rpc.gssd). Did you ever
> > > find a solution for this problem with rpcauth_lookup_credcache?
> >
> > http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git&a=commitdiff&h=23918b03060f6e572168fdde1798a905679d2e06
>
> Trond, this should be included into next stable, right ?
>
> It's fortunate because I know someone else who recently described me the
> same problem under the same circumstances when migrating from 2.6.22 to
> 2.6.27.

Now queued up in the 2.6.27-stable queue.

thanks,

greg k-h