Slower performance with lookupcache (2.6.30.2)

Slower performance with lookupcache (2.6.30.2)

[Simon Kirby]

Hello :)

I just noticed something interesting while benchmarking NFSv3 versus
GlusterFS.  With lookupcache enabled (all or positive), it seems that
successive executions of "du" are slower the second and further times. 
With lookupcache disabled, second and further executions are slightly
faster than the first but still slower than with lookupcache enabled:

# umount /nfs ; mount -t nfs 10.10.52.30:/home/nfs /nfs -o lookupcache=positive && repeat 3 /bin/sh -c 'time du -s /nfs/test ; sleep 3'
494616  /nfs/test

real    0m1.670s
user    0m0.028s
sys     0m0.344s
494616  /nfs/test

real    0m4.030s
user    0m0.052s
sys     0m0.536s
494616  /nfs/test

real    0m4.025s
user    0m0.060s
sys     0m0.608s

With lookupcache=none:

# umount /nfs ; mount -t nfs 10.10.52.30:/home/nfs /nfs -o lookupcache=none && repeat 3 /bin/sh -c 'time du -s /nfs/test ; sleep 3'
494616  /nfs/test

real    0m5.362s
user    0m0.044s
sys     0m0.924s
494616  /nfs/test

real    0m4.496s
user    0m0.060s
sys     0m0.828s
494616  /nfs/test

real    0m4.497s
user    0m0.052s
sys     0m0.780s

In this case, /nfs/test is just a copy of /usr made on the server.  The
only difference is "lookupcache".  When set to "all" or "positive", the
first sweep is much faster than "none", but the following sweeps are
slower.

nfsstat shows that "getattr" is called many more times on the second and
third sweeps:

# umount /nfs ; mount -t nfs 10.10.52.30:/home/nfs /nfs -o lookupcache=all && repeat 3 /bin/sh -c 'cat /proc/net/rpc/nfs > /tmp/x ; time du -s /nfs/test ; nfsstat -c3 -S /tmp/x ; sleep 3'
494616  /nfs/test

real    0m1.684s
user    0m0.036s
sys     0m0.316s
Client rpc stats:
calls      retrans    authrefrsh
8622       0          0       

Client nfs v3:
null         getattr      setattr      lookup       access       readlink     
0         0% 3649     42% 0         0% 820       9% 1826     21% 0         0% 
read         write        create       mkdir        symlink      mknod        
0         0% 0         0% 0         0% 0         0% 0         0% 0         0% 
remove       rmdir        rename       link         readdir      readdirplus  
0         0% 0         0% 0         0% 0         0% 8         0% 2319     26% 
fsstat       fsinfo       pathconf     commit       
0         0% 0         0% 0         0% 0         0% 

494616  /nfs/test

real    0m3.975s
user    0m0.052s
sys     0m0.672s
Client rpc stats:
calls      retrans    authrefrsh
25076      0          0       

Client nfs v3:
null         getattr      setattr      lookup       access       readlink     
0         0% 25076   100% 0         0% 0         0% 0         0% 0         0% 
read         write        create       mkdir        symlink      mknod        
0         0% 0         0% 0         0% 0         0% 0         0% 0         0% 
remove       rmdir        rename       link         readdir      readdirplus  
0         0% 0         0% 0         0% 0         0% 0         0% 0         0% 
fsstat       fsinfo       pathconf     commit       
0         0% 0         0% 0         0% 0         0% 

494616  /nfs/test

real    0m4.010s
user    0m0.056s
sys     0m0.616s
Client rpc stats:
calls      retrans    authrefrsh
25076      0          0       

Client nfs v3:
null         getattr      setattr      lookup       access       readlink     
0         0% 25076   100% 0         0% 0         0% 0         0% 0         0% 
read         write        create       mkdir        symlink      mknod        
0         0% 0         0% 0         0% 0         0% 0         0% 0         0% 
remove       rmdir        rename       link         readdir      readdirplus  
0         0% 0         0% 0         0% 0         0% 0         0% 0         0% 
fsstat       fsinfo       pathconf     commit       
0         0% 0         0% 0         0% 0         0% 

Adding "echo 1 > /proc/sys/vm/drop_caches" to the repeat loop makes the
readdirplus calls happen each time, but still with increased getattrs. 
With "echo 2 > /proc/sys/vm/drop_caches" instead, behaviour is always
fast (~1.6 seconds).

The lookupcache here seems to be increasing initial performance but then
seems to slow down cached performance by causing more getattrs than with
no lookupcache, perhaps for revalidation tests.

This is stock 2.6.30.2 on the server and client, NFSv3, EXT3 on the
server.

Simon-

Re: Slower performance with lookupcache (2.6.30.2)

[Trond Myklebust]

On Fri, 2009-07-24 at 16:13 -0700, Simon Kirby wrote:
> The lookupcache here seems to be increasing initial performance but then
> seems to slow down cached performance by causing more getattrs than with
> no lookupcache, perhaps for revalidation tests.

Yes. This is expected behaviour.

When you look up a dentry, you are also retrieving its attributes, so
the stat() call, can be entirely handled by the single LOOKUP rpc call.

If you are caching the dentries, then your stat() call doesn't need to
do a lookup, but it still needs to return valid attributes. Since
acregmin=3 seconds, then your test is likely to have to revalidate a
couple of times. However as long as there are no changes to the file,
then the attribute caching algorithm should get progressively more
aggressive. I'd therefore expect that if you change that to 'repeat 10'
or so, then the lookupcache=all/positive cases should show an
improvement.

   Trond

Re: Slower performance with lookupcache (2.6.30.2)

[Simon Kirby]

On Sat, Jul 25, 2009 at 12:51:43PM -0400, Trond Myklebust wrote:

> On Fri, 2009-07-24 at 16:13 -0700, Simon Kirby wrote:
> > The lookupcache here seems to be increasing initial performance but then
> > seems to slow down cached performance by causing more getattrs than with
> > no lookupcache, perhaps for revalidation tests.
> 
> Yes. This is expected behaviour.
> 
> When you look up a dentry, you are also retrieving its attributes, so
> the stat() call, can be entirely handled by the single LOOKUP rpc call.
> 
> If you are caching the dentries, then your stat() call doesn't need to
> do a lookup, but it still needs to return valid attributes. Since
> acregmin=3 seconds, then your test is likely to have to revalidate a
> couple of times. However as long as there are no changes to the file,
> then the attribute caching algorithm should get progressively more
> aggressive. I'd therefore expect that if you change that to 'repeat 10'
> or so, then the lookupcache=all/positive cases should show an
> improvement.

Ahh, yes, I see, there is.  If I run it longer, I see that it gets even
faster (0.6 seconds) for the forth run and then after a few more, back
up to 4 seconds once.  That makes sense now.

You say that LOOKUP is returning the attributes as well -- is it not
possible to operate the same way doing revalidation?  I was surprised
that there are so many fewer RPC calls during the first run (8622 calls
versus 25076 calls).  But, I suppose it's just readdirplus batching some
information together in a single call (since there are 23,650 files and
directories in the tree), and we probably wouldn't want to readdir all
the time.

Cheers,

Simon-

Re: Slower performance with lookupcache (2.6.30.2)

[Trond Myklebust]

On Mon, 2009-07-27 at 10:01 -0700, Simon Kirby wrote:
> You say that LOOKUP is returning the attributes as well -- is it not
> possible to operate the same way doing revalidation?

I'm not sure I understand you. Do you mean issue LOOKUP calls instead of
GETATTR calls when revalidating the file attribute information? Sure we
could, but LOOKUP is a more expensive operation than GETATTR on most
platforms: it requires the server to retrieve and process information
from both the parent directory and the file.

   Trond