slowness due to splitting into pages in nfs3svc_decode_writeargs()

slowness due to splitting into pages in nfs3svc_decode_writeargs()

[Bernd Schubert]

Hi,

I'm presently investigating why writing to a nfs exported lustre filesystem is 
rather slow. Reading from lustre over nfs about 200-300 MB/s, but writing to 
it over nfs is only 20-50MB/s (both with IPoIB). Writing directly to this 
lustre cluster is about 600-700 MB/s both reading and writing. Well, 200-300 
MB/s over NFS per client would be acceptable.

After several dozens of printks, systemtaps, etc I think its not the fault of 
lustre, but a generic nfsd and/or vfs problem.
In nfs3svc_decode_writeargs() all the data received are splitted into 
PAGE_SIZE, except the very first page. This page only gets 
PAGE_SIZE - header_length. So far no problem, but now on writing the pages in 
generic_file_buffered_write(), this function tries to write PAGE_SIZE. So it 
takes the first nfs page, which is PAGE_SIZE - header_length. 
To fill up to PAGE_SIZE it will take header_length from the second page. Of 
course, now there's also only PAGE_SIZE - header_length for the 2nd nfs page 
left. 
It will continue this way until the last page is written. Don't know why this 
doesn't show a big effect on other file system. Well, maybe it does, but 
nobody did notice it before?

Well, I have no idea if generic_file_buffered_write() really has to do what it 
presently does. But lets first stay at nfs, is it really necessary to already 
split up the data into pages? 

Using this patch I get write speed of about 200 MB/s, even with kernel 
debugging enabled and several left-over printks 

-- nfs3xdr.c.bak	2007-07-09 01:32:17.000000000 +0200
+++ nfs3xdr.c	2007-08-31 19:29:31.000000000 +0200
@@ -405,16 +405,8 @@ nfs3svc_decode_writeargs(struct svc_rqst
 		len = args->len = max_blocksize;
 	}
 	rqstp->rq_vec[0].iov_base = (void*)p;
-	rqstp->rq_vec[0].iov_len = rqstp->rq_arg.head[0].iov_len - hdr;
-	v = 0;
-	while (len > rqstp->rq_vec[v].iov_len) {
-		len -= rqstp->rq_vec[v].iov_len;
-		v++;
-		rqstp->rq_vec[v].iov_base = page_address(rqstp->rq_pages[v]);
-		rqstp->rq_vec[v].iov_len = PAGE_SIZE;
-	}
-	rqstp->rq_vec[v].iov_len = len;
-	args->vlen = v + 1;
+	rqstp->rq_vec[0].iov_len = len;
+	args->vlen = 1;
 	return 1;
 }


Cheers,
Bernd 

-- 
Bernd Schubert
Q-Leap Networks GmbH

-------------------------------------------------------------------------
This SF.net email is sponsored by: Splunk Inc.
Still grepping through log files to find problems?  Stop.
Now Search log events and configuration files using AJAX and a browser.
Download your FREE copy of Splunk now >>  http://get.splunk.com/
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: slowness due to splitting into pages in nfs3svc_decode_writeargs()

[J. Bruce Fields]

On Fri, Aug 31, 2007 at 08:03:30PM +0200, Bernd Schubert wrote:
> I'm presently investigating why writing to a nfs exported lustre filesystem is 
> rather slow. Reading from lustre over nfs about 200-300 MB/s, but writing to 
> it over nfs is only 20-50MB/s (both with IPoIB). Writing directly to this 
> lustre cluster is about 600-700 MB/s both reading and writing. Well, 200-300 
> MB/s over NFS per client would be acceptable.
> 
> After several dozens of printks, systemtaps, etc I think its not the fault of 
> lustre, but a generic nfsd and/or vfs problem.

Thanks for looking into this!

> In nfs3svc_decode_writeargs() all the data received are splitted into 
> PAGE_SIZE, except the very first page. This page only gets 
> PAGE_SIZE - header_length. So far no problem, but now on writing the pages in 
> generic_file_buffered_write(), this function tries to write PAGE_SIZE. So it 
> takes the first nfs page, which is PAGE_SIZE - header_length. 
> To fill up to PAGE_SIZE it will take header_length from the second page. Of 
> course, now there's also only PAGE_SIZE - header_length for the 2nd nfs page 
> left. 
> It will continue this way until the last page is written. Don't know why this 
> doesn't show a big effect on other file system. Well, maybe it does, but 
> nobody did notice it before?

Hm.  Any chance this is the same problem?:

	http://marc.info/?l=linux-nfs&m=112289652218095&w=2

> Using this patch I get write speed of about 200 MB/s, even with kernel 
> debugging enabled and several left-over printks 

At too high a cost, unfortunately:

> -- nfs3xdr.c.bak	2007-07-09 01:32:17.000000000 +0200
>  	rqstp->rq_vec[0].iov_base = (void*)p;
...
> +	rqstp->rq_vec[0].iov_len = len;
> +	args->vlen = 1;

There's no guarantee the later pages in the rq_pages array are
contiguous in memory after the first one, so the rest of that iovec
probably has random data in it.

(You might want to add to your tests some checks that the right data
still gets to the file afterwards.)

--b.

-------------------------------------------------------------------------
This SF.net email is sponsored by: Splunk Inc.
Still grepping through log files to find problems?  Stop.
Now Search log events and configuration files using AJAX and a browser.
Download your FREE copy of Splunk now >>  http://get.splunk.com/
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: slowness due to splitting into pages in nfs3svc_decode_writeargs()

[Brian J. Murrell]

[-- Attachment #1.1: Type: text/plain, Size: 421 bytes --]

On Fri, 2007-08-31 at 14:45 -0400, J. Bruce Fields wrote:
> 
> Hm.  Any chance this is the same problem?:
> 
> 	http://marc.info/?l=linux-nfs&m=112289652218095&w=2

Did this ever land anywhere?

b.

-- 
A day in the yard with my son is just like a day at work.  He goes
hunting around for stuff and brings it back to me and says: "Hey Dad,
look what I found.  The money is for me and the screw is for you."

[-- Attachment #1.2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 189 bytes --]

[-- Attachment #2: Type: text/plain, Size: 315 bytes --]

-------------------------------------------------------------------------
This SF.net email is sponsored by: Splunk Inc.
Still grepping through log files to find problems?  Stop.
Now Search log events and configuration files using AJAX and a browser.
Download your FREE copy of Splunk now >>  http://get.splunk.com/

[-- Attachment #3: Type: text/plain, Size: 140 bytes --]

_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: slowness due to splitting into pages in nfs3svc_decode_writeargs()

[J. Bruce Fields]

On Fri, Aug 31, 2007 at 02:52:15PM -0400, Brian J. Murrell wrote:
> On Fri, 2007-08-31 at 14:45 -0400, J. Bruce Fields wrote:
> > 
> > Hm.  Any chance this is the same problem?:
> > 
> > 	http://marc.info/?l=linux-nfs&m=112289652218095&w=2
> 
> Did this ever land anywhere?

No--I think there were some discussion of problems in the followup
posts.

--b.

-------------------------------------------------------------------------
This SF.net email is sponsored by: Splunk Inc.
Still grepping through log files to find problems?  Stop.
Now Search log events and configuration files using AJAX and a browser.
Download your FREE copy of Splunk now >>  http://get.splunk.com/
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: slowness due to splitting into pages in nfs3svc_decode_writeargs ()

[Bernd Schubert]

Hello Bruce,

thanks for your help!

On Friday 31 August 2007, J. Bruce Fields wrote:
> On Fri, Aug 31, 2007 at 08:03:30PM +0200, Bernd Schubert wrote:
> > I'm presently investigating why writing to a nfs exported lustre
> > filesystem is rather slow. Reading from lustre over nfs about 200-300
> > MB/s, but writing to it over nfs is only 20-50MB/s (both with IPoIB).
> > Writing directly to this lustre cluster is about 600-700 MB/s both
> > reading and writing. Well, 200-300 MB/s over NFS per client would be
> > acceptable.
> >
> > After several dozens of printks, systemtaps, etc I think its not the
> > fault of lustre, but a generic nfsd and/or vfs problem.
>
> Thanks for looking into this!

I will give these thanks to my boss who is paying me for this work :)


>
> > In nfs3svc_decode_writeargs() all the data received are splitted into
> > PAGE_SIZE, except the very first page. This page only gets
> > PAGE_SIZE - header_length. So far no problem, but now on writing the
> > pages in generic_file_buffered_write(), this function tries to write
> > PAGE_SIZE. So it takes the first nfs page, which is PAGE_SIZE -
> > header_length.
> > To fill up to PAGE_SIZE it will take header_length from the second page.
> > Of course, now there's also only PAGE_SIZE - header_length for the 2nd
> > nfs page left.
> > It will continue this way until the last page is written. Don't know why
> > this doesn't show a big effect on other file system. Well, maybe it does,
> > but nobody did notice it before?
>
> Hm.  Any chance this is the same problem?:
>
> 	http://marc.info/?l=linux-nfs&m=112289652218095&w=2

Looks similar.

+	if (vec[0].iov_len + vec[vlen-1].iov_len != PAGE_CACHE_SIZE)
+		return 0;
+	for (i = 1; i < vlen - 1; ++i) {
+		if (vec[i].iov_len != PAGE_CACHE_SIZE)
+			return 0;
+	}

I tried to say in my last mail:

vec[0].iov_len           = PAGE_PAGE_SIZE - headerlength
vec[1 ... n - 1].iov_len = PAGE_PAGE_SIZE
vec[n].iov_len           = headerlength


This looks like it needs quite some cpu cycles

+               memmove(this_page + chunk0, this_page, chunk1);
+               memcpy(this_page, prev_page + chunk1, chunk0);

I will test the patch tomorrow.

>
> > Using this patch I get write speed of about 200 MB/s, even with kernel
> > debugging enabled and several left-over printks
>
> At too high a cost, unfortunately:
> > -- nfs3xdr.c.bak	2007-07-09 01:32:17.000000000 +0200
> >  	rqstp->rq_vec[0].iov_base = (void*)p;
>
> ...
>
> > +	rqstp->rq_vec[0].iov_len = len;
> > +	args->vlen = 1;
>
> There's no guarantee the later pages in the rq_pages array are
> contiguous in memory after the first one, so the rest of that iovec
> probably has random data in it.

Hmm, its some time since I last read rfc1813, but I can't remember something 
like 'data are send in pages and pages may have random order'. So I guess 
some kind of multi-threading is filling in the data the client is sending?
Given the performance impact this has, maybe single-threading per client 
request would be better?
Can you point me to the corresponding function?

>
> (You might want to add to your tests some checks that the right data
> still gets to the file afterwards.)

Hmm, I need to put the data on a ram-disk. All raid-boxes sufficiently fast 
for this operation are in use for lustre storage.


Thanks again,
Bernd

-------------------------------------------------------------------------
This SF.net email is sponsored by: Splunk Inc.
Still grepping through log files to find problems?  Stop.
Now Search log events and configuration files using AJAX and a browser.
Download your FREE copy of Splunk now >>  http://get.splunk.com/
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: slowness due to splitting into pages in?nfs3svc_decode_writeargs()

[J. Bruce Fields]

On Fri, Aug 31, 2007 at 11:34:49PM +0200, Bernd Schubert wrote:
> On Friday 31 August 2007, J. Bruce Fields wrote:
> > There's no guarantee the later pages in the rq_pages array are
> > contiguous in memory after the first one, so the rest of that iovec
> > probably has random data in it.
> 
> Hmm, its some time since I last read rfc1813, but I can't remember something 
> like 'data are send in pages and pages may have random order'. So I guess 
> some kind of multi-threading is filling in the data the client is sending?

The data all arrives in one big chunk, in order.  But then we have to
put it some place.  The kernel almost never tries to allocate more than
one contiguous page of memory--memory fragmentation can make it
difficult to do that reliably--so we just ask for a bunch of pages to
put the data in, which may represent memory from all over the place,
store those pages into an array, and receive the data into those pages
in the order they're listed in the array.

--b.

-------------------------------------------------------------------------
This SF.net email is sponsored by: Splunk Inc.
Still grepping through log files to find problems?  Stop.
Now Search log events and configuration files using AJAX and a browser.
Download your FREE copy of Splunk now >>  http://get.splunk.com/
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: slowness due to splitting into pages in?nfs3svc_decode_writeargs()

[Bernd Schubert]

On Friday 31 August 2007, J. Bruce Fields wrote:
> On Fri, Aug 31, 2007 at 11:34:49PM +0200, Bernd Schubert wrote:
> > On Friday 31 August 2007, J. Bruce Fields wrote:
> > > There's no guarantee the later pages in the rq_pages array are
> > > contiguous in memory after the first one, so the rest of that iovec
> > > probably has random data in it.
> >
> > Hmm, its some time since I last read rfc1813, but I can't remember
> > something like 'data are send in pages and pages may have random order'.
> > So I guess some kind of multi-threading is filling in the data the client
> > is sending?
>
> The data all arrives in one big chunk, in order.  But then we have to
> put it some place.  The kernel almost never tries to allocate more than
> one contiguous page of memory--memory fragmentation can make it
> difficult to do that reliably--so we just ask for a bunch of pages to
> put the data in, which may represent memory from all over the place,
> store those pages into an array, and receive the data into those pages
> in the order they're listed in the array.

Ah, now I understand, thanks! I'm still used to userspace programming (*)


Thanks,
Bernd


PS: (*) Don't know if I ever will really like kernel programming - it 
remembers me to metal-organic chemistry, everything is a 100 times more 
difficult than usually, even simple weighing 100g of a substance might take a 
few hours.



-------------------------------------------------------------------------
This SF.net email is sponsored by: Splunk Inc.
Still grepping through log files to find problems?  Stop.
Now Search log events and configuration files using AJAX and a browser.
Download your FREE copy of Splunk now >>  http://get.splunk.com/
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: slowness due to splitting into pages in nfs3svc_decode_writeargs ()

[Bernd Schubert]

On Friday 31 August 2007, J. Bruce Fields wrote:
> On Fri, Aug 31, 2007 at 02:52:15PM -0400, Brian J. Murrell wrote:
> > On Fri, 2007-08-31 at 14:45 -0400, J. Bruce Fields wrote:
> > > Hm.  Any chance this is the same problem?:
> > >
> > > 	http://marc.info/?l=linux-nfs&m=112289652218095&w=2
> >
> > Did this ever land anywhere?
>
> No--I think there were some discussion of problems in the followup
> posts.

To sum up this discussion:

There are two choices to move the data:

1.) To page 2 ... n - this will overwrite nfsv4 at the end of page n.

2.) To page 1 ... n - 1 - this will overwrite the header, thus, all pointers 
to that memory will point to wrong data now.

Seems both aproaches are troublesome and nobody bothered to implement it. Not 
that I much like the idea of data moving at all, but what about

3.) On allocating the pages, allocate one page more than required. After 
filling in page 1, skip page 2 and proceed with page 3.
Now we would have space to properly move the data later on, thus:

memcpy  (page2, page1 + hdr, PAGE_SIZE - hdr_length)
memcpy  (page2 + PAGE_SIZE - hdr_length, page3, hdr_length)

memmove(page3, page3 + hdr_length, PAGE_SIZE - hdr_length)
[...] 


Can you point me to the function assigning the data-block from the network to 
the page-vector?

Thanks,
Bernd

-------------------------------------------------------------------------
This SF.net email is sponsored by: Splunk Inc.
Still grepping through log files to find problems?  Stop.
Now Search log events and configuration files using AJAX and a browser.
Download your FREE copy of Splunk now >>  http://get.splunk.com/
_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs

Re: slowness due to splitting into pages in nfs3svc_decode_writeargs ()

[Bernd Schubert]

[-- Attachment #1: Type: text/plain, Size: 637 bytes --]

On Friday 31 August 2007, J. Bruce Fields wrote:
>
> Hm.  Any chance this is the same problem?:
>
> 	http://marc.info/?l=linux-nfs&m=112289652218095&w=2
>

I have slightly modified Olafs patch, now the last page is saved and restored. 
Well there's a problem with it, if there's more than one thread, files over 
nfs become corrupted, if there's only one thread everything is fine. So far I 
have no idea whats going on.

In principal we could do the same in do_readv_writev(), the iov vector there 
should hopefully only belong to one thread. 

Anyway, using this patch, the nfs-write speed on lustre is about 200 MB/s.


Cheers,
Bernd

[-- Attachment #2: nfs_align.patch_racy --]
[-- Type: text/x-diff, Size: 2875 bytes --]

Index: linux-2.6.20.3/fs/nfsd/vfs.c
===================================================================
--- linux-2.6.20.3.orig/fs/nfsd/vfs.c	2007-09-03 14:41:54.000000000 +0200
+++ linux-2.6.20.3/fs/nfsd/vfs.c	2007-09-03 17:41:36.000000000 +0200
@@ -900,6 +900,48 @@
 	mutex_unlock(&dentry->d_inode->i_mutex);
 }
 
+/*
+ * Helper function to page-align the write payload.
+ */
+static int
+nfsd_page_align_payload(struct kvec *vec, int vlen)
+{
+	unsigned char *this_page, *prev_page;
+	int i, chunk0, chunk1;
+
+	/* The following checks are just paranoia */
+	if (vlen < 2)
+		return 0;
+
+	if (vec[0].iov_len + vec[vlen-1].iov_len != PAGE_CACHE_SIZE)
+		return 0;
+	for (i = 1; i < vlen - 1; ++i) {
+		if (vec[i].iov_len != PAGE_CACHE_SIZE)
+			return 0;
+	}
+
+	chunk0 = vec[0].iov_len;
+	chunk1 = PAGE_CACHE_SIZE - chunk0;
+
+	this_page = (unsigned char *) vec[vlen-1].iov_base;
+	for (i = vlen-1; i; --i) {
+		prev_page = (unsigned char *) vec[i-1].iov_base;
+
+		/* Push trailing partial page so it's
+			* aligned with the end of the page, then
+			* pull up the missing chunk from the previous
+			* page */
+		memmove(this_page + chunk0, this_page, chunk1);
+		memcpy(this_page, prev_page + chunk1, chunk0);
+		vec[i].iov_len = PAGE_CACHE_SIZE;
+		this_page = prev_page;
+	}
+
+	return 1;
+}
+
+
+
 static __be32
 nfsd_vfs_write(struct svc_rqst *rqstp, struct svc_fh *fhp, struct file *file,
 				loff_t offset, struct kvec *vec, int vlen,
@@ -912,6 +954,8 @@
 	__be32			err = 0;
 	int			host_err;
 	int			stable = *stablep;
+	char 			*tmp_page; /* used for page alignement */
+	int			did_align = 0;
 
 #ifdef MSNFS
 	err = nfserr_perm;
@@ -944,6 +988,26 @@
 	if (stable && !EX_WGATHER(exp))
 		file->f_flags |= O_SYNC;
 
+	/* save the last vector element, besides file data it may have
+	 * nfsv4 data, which will be overwritten by the alignement hack */
+	tmp_page = (char *) __get_free_page(GFP_KERNEL);
+	if (tmp_page
+	&& (offset < inode->i_size)
+	&& vec->iov_len != PAGE_CACHE_SIZE) {
+		memcpy(tmp_page, vec[vlen - 1].iov_base, PAGE_SIZE);
+
+		/* Hack: if we're rewriting the file, make sure
+		* we align the iovec properly to avoid costly
+		* read-modify-write operations on the block devices.
+		* This hack can go away once we have generic_file_writev.
+		*/
+
+		if (nfsd_page_align_payload(vec, vlen)) {
+			did_align = 1;
+			vec++, vlen--;
+		}
+	}
+
 	/* Write the data. */
 	oldfs = get_fs(); set_fs(KERNEL_DS);
 	host_err = vfs_writev(file, (struct iovec __user *)vec, vlen, &offset);
@@ -953,6 +1017,12 @@
 		fsnotify_modify(file->f_path.dentry);
 	}
 
+	/* restore the last vector element */
+	if (did_align) {
+		memcpy(vec[vlen - 1].iov_base, tmp_page, PAGE_SIZE);
+		free_page((unsigned long) tmp_page);
+	}
+
 	/* clear setuid/setgid flag after write */
 	if (host_err >= 0 && (inode->i_mode & (S_ISUID | S_ISGID)))
 		kill_suid(dentry);

[-- Attachment #3: Type: text/plain, Size: 315 bytes --]

-------------------------------------------------------------------------
This SF.net email is sponsored by: Splunk Inc.
Still grepping through log files to find problems?  Stop.
Now Search log events and configuration files using AJAX and a browser.
Download your FREE copy of Splunk now >>  http://get.splunk.com/

[-- Attachment #4: Type: text/plain, Size: 140 bytes --]

_______________________________________________
NFS maillist  -  NFS@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/nfs