Why will NFS client spend so much time on file open?

Why will NFS client spend so much time on file open?

[Xin Zhao]

Hi,

I did Apache benchmark and collected the performance results at the
file system call level.
The microbenchmark results were collected when I did "make" on Apache
source code.

The results are very interesting:

		      open	        read		
Total Time (s)  21.599 	         15.948 											Count		   310274 	
 98028 											Time/Call (ms)	69.61 	         162.69

The results show that NFS spent even more time on file open than on
file read. But this result confuses me: what does NFS do to open a
file? As far as I know, it just issues a lookup() RPC to get file
handle, and maybe a getattr() RPC to get file attributes. This should
not take so much time. Can someone explain why this could happen?

Thanks,
-x

Re: Why will NFS client spend so much time on file open?

[Trond Myklebust]

On Thu, 2006-08-24 at 03:15 -0400, Xin Zhao wrote:
> Hi,
> 
> I did Apache benchmark and collected the performance results at the
> file system call level.
> The microbenchmark results were collected when I did "make" on Apache
> source code.
> 
> The results are very interesting:
> 
> 		      open	        read		
> Total Time (s)  21.599 	         15.948 											Count		   310274 	
>  98028 											Time/Call (ms)	69.61 	         162.69
> 
> The results show that NFS spent even more time on file open than on
> file read. But this result confuses me: what does NFS do to open a
> file? As far as I know, it just issues a lookup() RPC to get file
> handle, and maybe a getattr() RPC to get file attributes. This should
> not take so much time. Can someone explain why this could happen?

It is impossible to tell without more information.

Are these all open() for read, or are you mixing in other stuff like
O_CREAT, O_TRUNC and/or O_EXCL? All of those flags will have an impact
on the open() latency.

What is your expectation w.r.t. read cache misses? Is the read cache
always guaranteed to be cold on every call to read(), or is your test
cycling through the same data over and over again so that the caches are
kept hot?

Cheers,
  Trond